Topic: Audio record timer records too long (Read 5080 times)

MrC · « **on:** June 29, 2010, 11:34:06 am »

I have a timer set to record an audio stream from an Internet station. On two occasions now, it has recorded well beyond the 2 hours that the event is scheduled to record. Yesterday's program recorded for 21:58:01 (21 hours, 58 minutes). The other one was something like 11 hours.

Can anyone offer some explanations as to why this occurs?

Matt · « **Reply #1 on:** June 29, 2010, 02:48:10 pm »

Are you using the Scheduler or the 'Open URL...' method for recording?

Could you share the URL so we could test the same stream here?

Thanks.

MrC · « **Reply #2 on:** June 29, 2010, 02:54:47 pm »

Thanks Matt,

Scheduler Task w/URL:

http://yp.shoutcast.com/sbin/tunein-station.pls?id=542012&file=filename.pls

The stream has recorded each time... just too long twice by many hours. The URL could affect the record duration?

Matt · « **Reply #3 on:** June 29, 2010, 03:43:38 pm »

Can you figure out anything that triggers the over-recording?

For example, if you have Media Center closed (Media Server running) or are doing some other special thing with the program?

What does the display show in Scheduler when it's recording past when it should have stopped?

Thanks.

Matt · « **Reply #4 on:** June 29, 2010, 04:05:24 pm »

I wonder if this _is_ station specific.

Because what we're doing is getting as much of the stream as possible while recording for the amount of time you set. If a station provides data faster than real-time, you will get a file that's longer than the recording time.

So when I record for one-minute, I'm able to record about 5 minutes from that station. I think that means it's not a true stream, but really just a big file sitting there.

Normally we're recording from a live stream where you can't read faster than real-time.

Does that make sense? Is that station time-delayed (or looped) somehow?

Thanks.

MrC · « **Reply #5 on:** June 29, 2010, 04:59:15 pm »

Interesting. I played the "live" stream several times, and it a) it caches 1 minute beyond the stream length (at the beginning) and b) it once repeated the same "live" stream if the stream is restarted (for small chunks).

I recorded for 5 minutes and got 6 minutes.

I wonder if they could be appending the new program (pre-recorded) to the stream (file) and that some calculation is going haywire. I don't know the technical aspects of how their streaming works.

The only real issue is that the recoding is > 300 Meg, rather than the 24 Meg expected.

Is there any way for the MC scheduler to know that it has accepted the allotted file size (or program duration) in this case? This stream is 32kbps, so 2 hours should be about 29,4912,00 bytes +- some fudge. Certainly 300meg is about 10 times too large.

(btw: I tried creating a record task, and use the URL http://sc1.mainstreamnetwork.com:9042 as both the Name and URL. MC happily recorded it, but the file was nowhere to be found. Perhaps an illegal name, that MC doesn't detect upon attempt to save?)

MrC · « **Reply #6 on:** July 26, 2010, 07:05:59 pm »

I think the theory here may be incorrect.

My 11am - 1pm Monday recording should have completed. It is now after 5pm. The Schedule indicates today's recording has Finished recording. Yet I look at My Connected Media, and see the file size is still growing, and the recording time is now 6 hours and 4 minutes, and continuing.

Any ideas?

MrC · « **Reply #7 on:** July 29, 2010, 11:44:20 am »

This happened 3 for 3 this week, Mon - Wed. All shows continued to record hours beyond the stop time.

Is there any way to Stop a recording in progress, short of shutting down MC?

Matt · « **Reply #8 on:** July 29, 2010, 01:37:33 pm »

If you watch the display in the task scheduler, does it countdown and report that it has stopped like expected?

I'm wondering if there could be some problem with international locales, or crossing midnight, or something?

MrC · « **Reply #9 on:** July 29, 2010, 01:44:53 pm »

The Task Schedule shows Status is Finished.

Yet, in the My Connected Media, both file sizes and recording duration continue to progress.

The station is in California, same location as I'm in, but the stream appears to be coming from Dallas (2 hour timezone difference).

There is no crossing of midnight at the recording time (11am-1pm PST or 1pm-3pm CST).

JimH · « **Reply #10 on:** July 29, 2010, 01:49:27 pm »

I suppose you double checked your system date.

MrC · « **Reply #11 on:** July 29, 2010, 01:51:09 pm »

My system is running NTP. Its always accurate within 10ths of a second.

[edit: sorry if this came of as curt. I have contractors in and out all day, and had to rush to answer the door ]

Matt · « **Reply #12 on:** July 29, 2010, 04:24:21 pm »

I haven't been able to reproduce this, but I did some code maintenance in the audio recording scheduler task code.

Please test once build 87 (or newer) is available and let me know if you're still seeing the issue.

Thanks.

MrC · « **Reply #13 on:** July 29, 2010, 05:38:20 pm »

Thanks Matt. I'll test. If there is additional tracing you need (wireshark, windows logs, etc.), let me know.

I'll create some additional timers so that we don't have to wait until Monday's timer.

MrC · « **Reply #14 on:** August 03, 2010, 07:17:03 pm »

So Sat, Sun, Mon, and Tue's recordings were all fine, using 15.0.87.

MrC · « **Reply #15 on:** August 09, 2010, 03:06:23 pm »

Since the .87 release, this has not reoccurred.

Matt · « **Reply #16 on:** August 09, 2010, 03:36:00 pm »

I never found a smoking gun, but something in the code cleanup must have been the ticket.

Thanks for all your help and patience on this one.

MrC · « **Reply #17 on:** August 26, 2010, 11:03:06 pm »

Ok, this rears its ugly head again. No ticket.

I have a 29.5 hour recording today. It recorded from yesterday at 11am, until I shut down MC today at 5:29pm to install a new version. That's 29.5 hours since the recording started.

MC says the file exists in my music folder by the name of:

  "E:\My Music\Global Village Wed: Yatrika Shah-Rais.mp3"

But it doesn't exist. The file name contains a colon, which of course is illegal, so the name is truncated on the file system to only:

  "Global Village Wed"

But that file is 0 bytes. And yet all 29.5 hours play.

I see no other modified large files (>1meg) files created yesterday when the recording was made, except some MC thumbnail files and this one:

  C:\...me...\AppData\Roaming\J River\Media Center 15\Temp\JR File Loader - 4268 (1).dat)

that seem to be candidates. So where is this file?

A comparable 2 hour file would be about 28Meg, so this one should be 14 times that.

MrC · « **Reply #18 on:** August 31, 2010, 05:29:51 pm »

Matt,

I'm two for two too long this week. I have another schedule recording from the same station tomorrow at 11am PST.

Can you set a two hour recording to see if you too can duplicate?

http://sc1.mainstreamnetwork.com:9042

TIA

Matt · « **Reply #19 on:** August 31, 2010, 07:14:11 pm »

Quote from: MrC on August 31, 2010, 05:29:51 pm

Can you set a two hour recording to see if you too can duplicate?

http://sc1.mainstreamnetwork.com:9042

I'll sure try.

I wonder, could the semi-colon be an important part of the bad behavior? Do you only have this problem when the recording name contains illegal file system characters?

MrC · « **Reply #20 on:** August 31, 2010, 08:08:42 pm »

Thanks.

I believe the colon in the file name is an unrelated problem (only 1 of 3 recordings -- that records long -- had a colon in the file name), but reveals two bugs:

1) the Scheduler Task's "Name" field probably should map illegal Win (or other OS) FS chars to legal ones (or disallow them)

2) since (1) did occur, MC did something with the file, but didn't/couldn't locate it where it indicated. MC happily placed the recording somewhere, hidden to users, and instead left a 0 byte file whose name was as sub-string of the task's "Name" field.

mike

Matt · « **Reply #21 on:** September 01, 2010, 04:36:52 pm »

Coming in build 104 (and later):
Fixed: Recording a stream with the scheduler that contained invalid characters in the name would cause problems.

I also added some logging, so please email me a log after it records too long. I'm a bit stumped by that.

MrC · « **Reply #22 on:** September 03, 2010, 10:35:59 am »

Ok, thanks. What log events would you like captured?

Matt · « **Reply #23 on:** September 03, 2010, 10:39:16 am »

Quote from: MrC on September 03, 2010, 10:35:59 am

Ok, thanks. What log events would you like captured?

Just log everything.

I've done a few test recordings, and have yet to see the problem. Hopefully the log will help.

Thanks.

MrC · « **Reply #24 on:** September 27, 2010, 03:21:07 pm »

Finally, after many attempts w/logging enabled, I now have a recording which is currently running long.

Shall I mail logs to matt @ jriver . com ?

MrC · « **Reply #25 on:** September 28, 2010, 05:19:30 pm »

I'm 2 for 2 this week, and have a second log if you'd like it. (you got the first one, yes?)

Matt · « **Reply #26 on:** September 28, 2010, 06:01:23 pm »

Quote from: MrC on September 28, 2010, 05:19:30 pm

you got the first one, yes?

Yes, but I haven't had a chance to review it.

I'll follow up in a day or two. In the meantime, feel free to send the second log.

Thanks.

Matt · « **Reply #27 on:** September 29, 2010, 10:42:51 am »

Thanks for the logs.

Here's a snapshot of the recording sections from each log:

Code: [Select]

LOG 1:
5964168: 1964: General: CSchedulerTaskRecordHelper::StartTask: Recording URL: http://sc1.mainstreamnetwork.com:9042
5964183: 1964: General: CSchedulerTaskRecordHelper::StartTask: Destination filename: E:\My Music\test.mp3
5964199: 1964: General: CSchedulerTaskRecordHelper::StartTask: Finish (1061 ms)
5964199: 1020: General: CSchedulerTaskRecordHelper::Thread: Start
5964215: 1020: General: CSchedulerTaskRecordHelper::Thread: Using reader
5964230: 1020: General: CSchedulerTaskRecordHelper::Thread: Starting read / write loop
13138077: 1020: General: CSchedulerTaskRecordHelper::Thread: Closing file
13138092: 1020: General: CSchedulerTaskRecordHelper::Thread: Finish (7173893 ms)

LOG 2:
5062451: 2216: General: CSchedulerTaskRecordHelper::StartTask: Recording URL: http://sc1.mainstreamnetwork.com:9042
5062451: 2216: General: CSchedulerTaskRecordHelper::StartTask: Destination filename: E:\My Music\Global Village Tues - Betto Arcos.mp3
5062482: 2216: General: CSchedulerTaskRecordHelper::StartTask: Finish (1030 ms)
5062482: 4268: General: CSchedulerTaskRecordHelper::Thread: Start
5062498: 4268: General: CSchedulerTaskRecordHelper::Thread: Using reader
5062513: 4268: General: CSchedulerTaskRecordHelper::Thread: Starting read / write loop
20394307: 4268: General: CSchedulerTaskRecordHelper::Thread: Closing file
20394323: 4268: General: CSchedulerTaskRecordHelper::Thread: Finish (15331841 ms)

So we read from the URL for:
LOG 1: 7173893 ms = ~2 hours
LOG 2: 15331841 ms = ~4.3 hours

Were both recordings scheduled for 2 hours? Did recording #1 end up the correct length?

Thanks.

MrC · « **Reply #28 on:** September 29, 2010, 10:48:08 am »

All recordings are scheduled to be 2 hours. When correct, they seem to record for about 2hr 3min.

I sent the first log at about 10 to 15 minutes or so after that cutoff. The recording continued until I quit MC when the recording was over 4hrs. I quit MC when the second recording was 4hr 17min.

I can resend the first log which would have the entire event sequence up to when I quit MC, but I suspect you won't need it since at the time I sent the log, the recording was already running long.

Update: I noticed that the file you are catching the log for in the first is test.mp3. This isn't the correct recording. You want to search for event time 7000623 in Log.txt.

Matt · « **Reply #29 on:** September 29, 2010, 11:07:32 am »

It looks like the problem is simply that the scheduler isn't stopping tasks when it should.

Could you email me a screenshot (Alt+PrtScn) of the Scheduler Task dialog for the recording you have scheduled? I'll use exactly the same settings and see what I find.

Thanks.

Matt · « **Reply #30 on:** September 29, 2010, 11:31:27 am »

Mystery solved.

It would over record near the end of the month, because the way we were adding to the current date didn't work. Basically, we'd say "September 34" and that would make the date become invalid instead of loop to the next month.

Look for a fix in build 123.

Thanks for all your help, and sorry this took so long to track down.

MrC · « **Reply #31 on:** September 29, 2010, 01:18:16 pm »

Ah ha! Nice, thanks so much! I can record with impunity now. :-)

INTERACT FORUM

Author Topic: Audio record timer records too long (Read 5080 times)