HR10-250 Rebooting when scanning for OTA channels

[Lord-dogbert]

Well, just checked the logs and found the box bouncing the other night for four hours straight, even getting badly fragmented errors now so i'll pull the drive and run efschk. At least it was more stable with cron disabled but i'm not happy with random reboots.

Now to go back to the other drivers and see if that helps.

[Jamie]

Well, just checked the logs and found the box bouncing the other night for four hours straight, even getting badly fragmented errors now so i'll pull the drive and run efschk. At least it was more stable with cron disabled but i'm not happy with random reboots.

Now to go back to the other drivers and see if that helps.

Post your logs. If you aren't seeing: "TvVideoManager[234]: Tmk Fatal Error: Thread died due to signal 11", I suspect this may be a different problem. The fragmentation errors don't sound related.

[Lord-dogbert]

Here's the log, the error # is 179 instead of 234. I have some other new errors that just started coming up as well. I haven't researched the other errors yet. What's interesting to me is the time stamp, most of the reboots occur at 9:09:58, one at 11:09:58. This is why I was thinking about cron.


Log cleared on Sat Jan 14, 2006 by TivoWebPlus
Jan 18 08:11:40 (none) ApgWriter[130]: Nested RETRY: b8e920 b3b0c0 50a6f4 5043e0 50020c 4f8380 4fdf48 526098
Jan 18 11:45:35 (none) FsRegion[180]: Free space too badly fragmented
Jan 18 22:43:00 (none) ApgWriter[130]: Nested RETRY: b8e920 b3b0c0 50a6f4 5043e0 50020c 4f8380 4fdf48 526098
Jan 19 07:59:50 (none) FsRegion[180]: Free space too badly fragmented
Jan 20 09:09:58 (none) TvVideoManager[179]: Tmk Fatal Error: Thread TvVideoManager <179> died due to signal 11
Jan 20 09:09:58 (none) TvVideoManager[179]: pc 0xaa7c90 status 0x8001d413 cause 0x000008 bva 0x81dbfde8 hi 00000000 lo 0x2f8ca738
Jan 20 09:09:58 (none) TvVideoManager[179]: R00 0x00000000 R01 0x9001d400 R02 0x00000000 R03 0x00000000
Jan 20 09:09:58 (none) TvVideoManager[179]: R04 0x7f5c5c54 R05 0x0fca17f5 R06 0x7f5c5c4c R07 0x00000000
Jan 20 09:09:58 (none) TvVideoManager[179]: R08 0x00000000 R09 0x7fff7480 R10 0x00000000 R11 0x00000002
Jan 20 09:09:58 (none) TvVideoManager[179]: R12 0x00000000 R13 0x10000000 R14 0x0000a510 R15 0x438c1000
Jan 20 09:09:58 (none) TvVideoManager[179]: R16 0x7fff7488 R17 0x7f5c5c1c R18 0x7f626c14 R19 0x7fff75e0
Jan 20 09:09:58 (none) TvVideoManager[179]: R20 0x00003f86 R21 0x7875ce32 R22 0x00000003 R23 0x7fff76b0
Jan 20 09:09:58 (none) TvVideoManager[179]: R24 0x00000000 R25 0x00b89778 R26 0x00000000 R27 0x00000000
Jan 20 09:09:58 (none) TvVideoManager[179]: R28 0x10048590 R29 0x7fff7470 R30 0x7f5c5130 R31 0x00aa7ba0
Jan 20 09:09:58 (none) TvVideoManager[179]: Tmk Thread Backtrace: aa7c90 992804 9b9cf0 9b8ce0 99ed10 99b8e8 dbca48 dbd410 dbd378 ded188 e09a98
Jan 20 09:09:58 (none) TvVideoManager[179]: Tmk Fatal Error: Thread died due to signal 11
Jan 20 09:09:58 (none) TvVideoManager[179]: Invoking rule 834: rebooting system
Jan 20 09:12:05 (none) TmkTransform::Trace[134]: File too short returning error
Jan 20 09:12:05 (none) TvRecorderUtil[134]: InvalidPezFile found in CleanupRecordingNoRetry
Jan 23 09:09:58 (none) TvVideoManager[179]: Tmk Fatal Error: Thread TvVideoManager <179> died due to signal 11
Jan 23 09:09:58 (none) TvVideoManager[179]: pc 0xaa7c90 status 0x8001d413 cause 0x000008 bva 0x81dbfde8 hi 00000000 lo 0x2dde2448
Jan 23 09:09:58 (none) TvVideoManager[179]: R00 0x00000000 R01 0xb001d400 R02 0x00000000 R03 0x00000000
Jan 23 09:09:58 (none) TvVideoManager[179]: R04 0x7f5c5f08 R05 0x0fcb03b3 R06 0x7f5c5f00 R07 0x00000000
Jan 23 09:09:58 (none) TvVideoManager[179]: R08 0x00000000 R09 0x7fff7480 R10 0x00000000 R11 0x00000002
Jan 23 09:09:58 (none) TvVideoManager[179]: R12 0x00000000 R13 0xc8000000 R14 0x0000a510 R15 0x0c666000
Jan 23 09:09:58 (none) TvVideoManager[179]: R16 0x7fff7488 R17 0x7f5c5ed0 R18 0x7f666c50 R19 0x7fff75e0
Jan 23 09:09:58 (none) TvVideoManager[179]: R20 0x00001317 R21 0x66c661c8 R22 0x00000003 R23 0x7fff76b0
Jan 23 09:09:58 (none) TvVideoManager[179]: R24 0x00000000 R25 0x00b89778 R26 0x00000000 R27 0x00000000
Jan 23 09:09:58 (none) TvVideoManager[179]: R28 0x10048590 R29 0x7fff7470 R30 0x7f5c4c04 R31 0x00aa7ba0
Jan 23 09:09:58 (none) TvVideoManager[179]: Tmk Thread Backtrace: aa7c90 992804 9b9cf0 9b8ce0 99ed10 99b8e8 dbca48 dbd410 dbd378 ded188 e09a98
Jan 23 09:09:58 (none) TvVideoManager[179]: Tmk Fatal Error: Thread died due to signal 11
Jan 23 09:09:58 (none) TvVideoManager[179]: Invoking rule 834: rebooting system
Jan 26 18:59:49 (none) FsRegion[180]: Free space too badly fragmented
Jan 26 18:59:49 (none) FsRegion[180]: Free space too badly fragmented
Jan 27 02:59:38 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 2937
Jan 27 02:59:38 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4001
Jan 27 02:59:38 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4433
Jan 27 02:59:38 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4351
Jan 27 02:59:38 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 938
Jan 27 02:59:38 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 1007
Jan 27 02:59:38 (none) Scheduler[181]: Error returned from HandleDataChanged: errDbNotFound
Jan 27 11:09:59 (none) TvVideoManager[179]: Tmk Fatal Error: Thread TvVideoManager <179> died due to signal 11
Jan 27 11:09:59 (none) TvVideoManager[179]: pc 0xaa7c90 status 0x8001d413 cause 0x000008 bva 0x81dbfde8 hi 00000000 lo 0x3990cd18
Jan 27 11:09:59 (none) TvVideoManager[179]: R00 0x00000000 R01 0xb001d400 R02 0x00000000 R03 0x00000000
Jan 27 11:09:59 (none) TvVideoManager[179]: R04 0x7f5c5e64 R05 0x0fcc4492 R06 0x7f5c5e5c R07 0x00000000
Jan 27 11:09:59 (none) TvVideoManager[179]: R08 0x00000000 R09 0x7fff7480 R10 0x00000000 R11 0x00000002
Jan 27 11:09:59 (none) TvVideoManager[179]: R12 0x00000000 R13 0x18000000 R14 0x0000a510 R15 0x33c28000
Jan 27 11:09:59 (none) TvVideoManager[179]: R16 0x7fff7488 R17 0x7f5c5e2c R18 0x7f613018 R19 0x7fff75e0
Jan 27 11:09:59 (none) TvVideoManager[179]: R20 0x000019fc R21 0xba4eb7a0 R22 0x00000003 R23 0x7fff76b0
Jan 27 11:09:59 (none) TvVideoManager[179]: R24 0x00000000 R25 0x00b89778 R26 0x00000000 R27 0x00000000
Jan 27 11:09:59 (none) TvVideoManager[179]: R28 0x10048590 R29 0x7fff7470 R30 0x7f5c50cc R31 0x00aa7ba0
Jan 27 11:09:59 (none) TvVideoManager[179]: Tmk Thread Backtrace: aa7c90 992804 9b9cf0 9b8ce0 99ed10 99b8e8 dbca48 dbd410 dbd378 ded188 e09a98
Jan 27 11:09:59 (none) TvVideoManager[179]: Tmk Fatal Error: Thread died due to signal 11
Jan 27 11:09:59 (none) TvVideoManager[179]: Invoking rule 834: rebooting system
Jan 27 18:22:47 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 2937
Jan 27 18:22:47 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4001
Jan 27 18:22:47 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4433
Jan 27 18:22:47 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4351
Jan 27 18:22:47 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 938
Jan 27 18:22:47 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 1007
Jan 27 18:22:47 (none) Scheduler[181]: Error returned from HandleDataChanged: errDbNotFound
Jan 27 18:29:49 (none) FsRegion[180]: Free space too badly fragmented
Jan 28 00:49:53 (none) FsRegion[180]: Free space too badly fragmented
Jan 28 02:38:03 (none) FsRegion[180]: Free space too badly fragmented
Jan 28 02:58:18 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 2937
Jan 28 02:58:18 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4001
Jan 28 02:58:18 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4433
Jan 28 02:58:18 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 4351
Jan 28 02:58:18 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 938
Jan 28 02:58:18 (none) Scheduler[181]: Error errDbNotFound: TvScheduler.C line 1007
Jan 28 02:58:18 (none) Scheduler[181]: Error returned from HandleDataChanged: errDbNotFound
Jan 28 03:49:49 (none) FsRegion[180]: Free space too badly fragmented
Jan 28 04:59:49 (none) FsRegion[180]: Free space too badly fragmented
Jan 28 09:09:58 (none) TvVideoManager[179]: Tmk Fatal Error: Thread TvVideoManager <179> died due to signal 11
Jan 28 09:09:58 (none) TvVideoManager[179]: pc 0xaa7c90 status 0x8001d413 cause 0x000008 bva 0x81dbfde8 hi 00000000 lo 0x3621d960
Jan 28 09:09:58 (none) TvVideoManager[179]: R00 0x00000000 R01 0xb001d400 R02 0x00000000 R03 0x00000000
Jan 28 09:09:58 (none) TvVideoManager[179]: R04 0x7f5c5f00 R05 0x0fcc8c9a R06 0x7f5c5ef8 R07 0x00000000
Jan 28 09:09:59 (none) TvVideoManager[179]: R08 0x00000000 R09 0x7fff7480 R10 0x00000000 R11 0x00000002
Jan 28 09:09:59 (none) TvVideoManager[179]: R12 0x00000000 R13 0x78000000 R14 0x0000a510 R15 0x6d0ab000
Jan 28 09:09:59 (none) TvVideoManager[179]: R16 0x7fff7488 R17 0x7f5c5ec8 R18 0x7f61ba34 R19 0x7fff75e0
Jan 28 09:09:59 (none) TvVideoManager[179]: R20 0x000005d4 R21 0x830a72dd R22 0x00000003 R23 0x7fff76b0
Jan 28 09:09:59 (none) TvVideoManager[179]: R24 0x00000000 R25 0x00b89778 R26 0x00000000 R27 0x00000000
Jan 28 09:09:59 (none) TvVideoManager[179]: R28 0x10048590 R29 0x7fff7470 R30 0x7f5c5168 R31 0x00aa7ba0
Jan 28 09:09:59 (none) TvVideoManager[179]: Tmk Thread Backtrace: aa7c90 992804 9b9cf0 9b8ce0 99ed10 99b8e8 dbca48 dbd410 dbd378 ded188 e09a98
Jan 28 09:09:59 (none) TvVideoManager[179]: Tmk Fatal Error: Thread died due to signal 11
Jan 28 09:09:59 (none) TvVideoManager[179]: Invoking rule 834: rebooting system
Jan 28 10:04:49 (none) FsRegion[180]: Free space too badly fragmented

[Jamie]

Here's the log, the error # is 179 instead of 234. I have some other new errors that just started coming up as well

That's the process id, and will vary. It does look like the same kind of crash, since the program counter at the crash site matches. I think the "badly fragmented" message may be unrelated.

The tivo software schedules tasks too, so the crashes at specific times doesn't necessarily implicate a cron job.

Are you absolutely sure your tivoapp doesn't have any bogus patches? There seems to be a lot of confusion about the right nocso patch locations for 3.1.5f. I recommend you never use the echo|dd style of patching unless you are certain of the patch location. A hexeditor is much safer, as described here.

[Lord-dogbert]

Are you absolutely sure your tivoapp doesn't have any bogus patches? There seems to be a lot of confusion about the right nocso patch locations for 3.1.5f. I recommend you never use the echo|dd style of patching unless you are certain of the patch location. A hexeditor is much safer, as described here.

Thanks Jamie,
I'll look into this and advise.

[Jamie]

I finally got a hold of a 3.1.5f tivoapp to analyze the crash dumps posted in this thread. These all seem to have a PC (program counter) value of 0xaa7c90. The code in the region is this:

0x00aa7c88 0x3c020000 lui    v0,0x0
0x00aa7c8c 0x005c1021 addu   v0,v0,gp
0x00aa7c90 0x8c4254a8 lw     v0,21672(v0)

v0 corresponds to R02, and you can see in the crash dump that it is zero at the crash. How can this be when it was just set to gp the instruction before? gp is R28 and has a nonzero value in the crash dump.

The answer is that everyone experiencing this issue seems to have applied a bogus nocso patch, just as isisyodin did. If you look at the bad patch he applied, it modifies the instruction at decimal file offset 6978700 = VMA 0x00aa7c8c. It replaces the instruction there with 0x3c020000, that is:

0x00aa7c8c 0x3c020000 lui    v0,0x0

Ah ha! That's how v0 is getting set to zero! devildog was right about this way back here.

Lessons learned:

• This has nothing to do with the backport drivers. It's simply the result of applying a tivoapp patch for the wrong tivoapp version.
• You can fix this by restoring the stock tivoapp and re-patch with the correct patch locations.
• Never blindly apply echo|dd style patches unless you are certain they are correct for your tivoapp version

Here are some useful tools to solve this kind of problem:

• Use a hex editor to apply patches. Make sure you are replacing the code you should be replacing.
• Build a cross compilation toolchain.
• Get a disassembler so you can see the code that is executing where the crash happens.
• Learn to read and understand mips assembly code.

[dengland]

Here are some useful tools to solve this kind of problem:

• Use a hex editor to apply patches. Make sure you are replacing the code you should be replacing.
• Build a cross compilation toolchain.
• Get a disassembler so you can see the code that is executing where the crash happens.
• Learn to read and understand mips assembly code.

I used the echo|dd patch method. I do plan on checking this with the disassembler, but I thought I would try something else quickly. I ran md5sum against the tivoapp on both of my HDTivos. I got the same value for both. Doesn't that say both files are identical?

[Jamie]

I used the echo|dd patch method. I do plan on checking this with the disassembler, but I thought I would try something else quickly. I ran md5sum against the tivoapp on both of my HDTivos. I got the same value for both. Doesn't that say both files are identical?

Yes, comparing md5sums of two files is a good way to check that they are identical. It's not guaranteed, but the probability that they are the same is very close to 1. Of course, you could also diff them.

[dengland]

Yes, comparing md5sums of two files is a good way to check that they are identical. It's not guaranteed, but the probability that they are the same is very close to 1. Of course, you could also diff them.

diff said they were the same. I will try and get the disassembler up and running to see if I have a valid CSO patch.

Good job on passing 2000 posts.

[Yazhol]

The answer is that everyone experiencing this issue seems to have applied a bogus nocso patch, just as isisyodin did. If you look at the bad patch he applied, it modifies the instruction at decimal file offset 6978700 = VMA 0x00aa7c8c. It replaces the instruction there with 0x3c020000, that is:

0x00aa7c8c 0x3c020000 lui    v0,0x0

Ah ha! That's how v0 is getting set to zero! devildog was right about this way back here.

Considering I've never applied the patch with an offset of 6978700, I've always used 6984684, this would not be the cause of the problem for me. I also did not apply any patches using the echo | dd method.

Lessons learned:This has nothing to do with the backport drivers. It's simply the result of applying a tivoapp patch for the wrong tivoapp version.

I'm still not convinced of this especially since applying the wrong tivoapp patch doesn't apply to me.

[LlamaLarry]

And yet, no word on what adapter you have, which backport drivers or where you got them. I am 3 days in on my freshly hacked box, using the backport drivers for a gigabit adapter. :::shrug:::

I tried duplicating your error, but could not. Is it only when scanning for OTA channels and/or changing OTA channels?

[Yazhol]

I'm using a linksys 200M, same as on my SD-DVR80.

The backported drivers I was using were the first ones available and I downloaded them from the thread on here.

No, it's not only when scanning for OTA. It was also happening when changing to a channel I don't receive. Any channel, not just OTA, like 75 or 77.

[Jamie]

I tried duplicating your error, but could not. Is it only when scanning for OTA channels and/or changing OTA channels?

Try applying the bad tivoapp patch, then compare the resulting register dump to that in the first post in this thread. I'm betting you'll see the same PC and register contents. Register dumps don't lie.

[LlamaLarry]

No, it's not only when scanning for OTA. It was also happening when changing to a channel I don't receive. Any channel, not just OTA, like 75 or 77.

Does the error manifest immediately, like after first reboot, or does it take a period of usage before the errors begin? I've definitely changed to channels I don't get while trying to figure out why this box is so god awful slow at twp and tytool extractions. Switching to blank channels definitely helps, but the box is still slightly slower than my SD boxes. Compared to my SD boxes the HD one does everything slower, but nothing is tying up cpu time in top so I don't know why it sucks so much. Was this "normal" behaviour on 3.x boxes? It may take a few mins to get the Main page of twp (v1.2.1) up.

Try applying the bad tivoapp patch, then compare the resulting register dump to that in the first post in this thread. I'm betting you'll see the same PC and register contents. Register dumps don't lie.

Sounds like a plan for the weekend as taking the TiVo down to "play" during the week may result in my family hanging me from a light pole.

[dengland]

why this box is so god awful slow at twp and tytool extractions. Switching to blank channels definitely helps, but the box is still slightly slower than my SD boxes. Compared to my SD boxes the HD one does everything slower

Before I manually upgraded from "e" to "f" on my original box, I pulled off a 5 hour file of HDNET coverage of the Shuttle launch just in case something went wrong. That took awhile: 5 1/2 hours even with the backport drivers.

My biggest time complaint is pressing the record button and waiting to have control of the box again.... Sorry - Off Topic.