Videos working, but not when filter generated

haus · Post by **haus** » Thu Dec 20, 2007 9:17 pm

I had this working yesterday; been tweaking things a bit (of course...) and now I can generate videos using the web interface just fine, but when I have a filter generate an email that then uses %EV% to email me the video, the video is un-playable.

Windows Media Player cannot play the file. The Player might not support the file type or might not support the codec that was used to compress the file.

When I re-generate the same video in the web interface and tell it to overwrite the existing video, the new one is about 100 bytes smaller, and it works perfectly.

I know not a lot of people are using videos because ffmpeg is sort of hard to get working, but has anyone seen anything like this? I've been trying to change my ffmpeg options to see if I can make it work, but nothing seems to help. I just don't understand what could be different between me clicking "Generate Video" and having it done by ZM as part of a filter. I can't imagine what I changed that would cause this.

Post by **zoneminder** » Thu Dec 20, 2007 10:36 pm

I don't know what this might be but will have a look and see what I can find. What format/type of video are you trying to create?

haus · Post by **haus** » Thu Dec 20, 2007 11:31 pm

Hi Phil,

I don't think it's something specifically in ZM; I actually had it working perfectly yesterday, and I have been trying to figure out what might have changed since then (assuming I broke something). I know I rebooted, which shouldn't have caused any problems. Also, manual video generation *is* working perfectly, so it's a mystery.

I've set it to default to WMV files since I'm viewing them on a PDA with Windows Mobile, but I've tried them all - MOV, MPG, AVI, etc. with the same result.

I suspect there's something weird when the videos are being generated, since ZM *does* generate a file that's 206 bytes too big (I counted the last couple of times - my original estimate was off) but fails to play. When I recreate the video manually, telling it to overwrite, it does so with a file that's 206 bytes smaller and works perfectly. But I will need to enable better debugging because my zmfilter amd zmvideo logs are of no help (they just say the video is being created, which I already know). Once I have a chance to get better logging I may have a clue as to what's being done differently when ZM creates the video via filter vs. manually. I'll update this thread if I find anything meaningful.

Greg

Post by **zoneminder** » Fri Dec 21, 2007 11:09 am

If you edit zm_funcs.php, find the createVideo function and add in a line

Code: Select all

error_log( $command );

before the exec line it will output the command to your web error log. You could then try running that command directly from a shell to see if you get the same size file.

Likewise, you can edit zmfilter.pl and search for zmvideo.pl in that file. Add a line afterwards thus

Code: Select all

Info( $command );

and save and restart. This will output the command into zmfilter.log.

It will be interesting to see if they are the same.

haus · Post by **haus** » Fri Dec 21, 2007 3:51 pm

Thanks Phil, will do. Not sure if I'll get to it before the mother in law arrives for Christmas, but curiosity beats cleaning the house so it might just happen...

haus · Post by **haus** » Mon Jan 14, 2008 7:03 am

Wow, I just can't seem to figure this out.

So I added the two commands, and restarted ZM, and here's what I know so far. When I created an alarm situation that tripped my filter containing %EV%, I looked at /var/log/messages:

Code: Select all

Jan 13 21:52:59 dvr zma_m8[5339]: INF [IN_Living_Room: 027 - Gone into alarm state]
Jan 13 21:53:06 dvr zma_m8[5339]: INF [IN_Living_Room: 078 - Gone into alert state]
Jan 13 21:53:12 dvr zma_m8[5339]: INF [IN_Living_Room: 102 - Left alarm state (5905) - 85(51) images]
Jan 13 21:53:18 dvr zmfilter[5290]: INF [/usr/bin/zmvideo.pl -e 5905 -r 1 -s 1 -f wmv]
Jan 13 21:53:19 dvr zmvideo[5419]: INF [Creating video file Event-5905-r1-s1.wmv for event 5905]
Jan 13 21:53:19 dvr zmvideo[5419]: INF [Finished Event-5905-r1-s1.wmv]
Jan 13 21:53:19 dvr zmfilter[5290]: INF [Creating notification email]
Jan 13 21:53:19 dvr zmfilter[5290]: INF [/usr/bin/zmvideo.pl -e 5905 -r 1 -s 1 -f wmv]
Jan 13 21:53:20 dvr zmvideo[5422]: INF [Video file Event-5905-r1-s1.wmv already exists for event 5905]
Jan 13 21:53:20 dvr zmfilter[5290]: INF [Sending notification email 'IN_Living_Room Alarm']
Jan 13 21:53:20 dvr zmfilter[5290]: INF [Attaching '8/5905/011-capture.jpg]
Jan 13 21:53:20 dvr zmfilter[5290]: INF [Attaching '8/5905/Event-5905-r1-s1.wmv]
Jan 13 21:53:26 dvr zmfilter[5290]: INF [Notification email sent]

I received the email, and the video was not playable:

Code: Select all

"Windows Media Player cannot play the file. The Player might not support the file type or might not support the codec that was used to compress the file."

Video parameters for the "bad" video in the video detail screen for that event:

Format: wmv
Size: 525584
Rate: Real
Scale: Actual

Then I delete the "bad" video in that window, reset the video format, frame rate, and size to wmv, Real, and Actual, and press "Generate Video".

The resulting file size/info is:

Format: wmv
Size: 525377
Rate: Real
Scale: Actual

This time the video plays perfectly.

zmfilter.log shows:

Code: Select all

01/13/08 21:53:18.948620 zmfilter[5290].INF [/usr/bin/zmvideo.pl -e 5905 -r 1 -s 1 -f wmv]

In the web error log is this:

Code: Select all

 /usr/bin/zmvideo.pl -e 5905 -f wmv -r 1.00 -s 1.00, referer: http://192.168.0.80/index.php?view=video
&eid=5905&delete=0

This time, I re-ran that exact command doing a linux cut/paste, and I got:

Code: Select all

root@dvr:/var/log/apache2# Value "1.00," invalid for option s (real number expected)

When I remove the comma from that line, it works fine and I get a working video.

The differences in what is passed to zmvideo.pl seem to be the decimal and two zeroes for the rate and scale parameters and the command and referer line for the manual video generation. When I run either zmvideo.pl cmomand from the shell, assuming I remove the comma, I get a playable video in both cases. It only breaks when zmfilter runs it in the background. Still a mystery.

Quick edit:

I also tried removing the %EIM% from the email message, and finally I unchecked "generate video" in the filter itself (because the %EV% directive tries to generate it also, hence the message about the video file already existing in the first code block above), and I still get an unplayable video from the filter.

I wonder if I could pass one of the unplayable videos through some sort of video file software that could tell what the problem is. Obviously since the file sizes are very close, it's a trivial thing. Most of the data is there, but something is off just enough that it can't play.

hvisser · Post by **hvisser** » Thu Jan 17, 2008 11:54 pm

I have the same problem.

A filter generated mpg will not play in Media Player or GOM Player but it will play in Quicktime and Nero Showtime.

If I go to the same event in ZM, delete the generated mpg and regenerate it, it will play fine in all of the above.

The filter generated file is 601099bytes and the manual generated file is 600064bytes

When I open both in a text editor the filter genrated has the following obvious text at the start:

Code: Select all

Output #0, mpeg, to 'Event-217-r1-s1.mpg':
  Stream #0.0: Video: mpeg1video, yuv420p, 352x288, q=2-31, 200 kb/s, 25.00 fps(c)
Stream mapping:
  Stream #0.0 -> #0.0
Press [q] to stop encoding

What's worse is it worked fine about an hour ago and I'm not really sure what I've done to 'break' it.

haus · Post by **haus** » Fri Jan 18, 2008 12:13 am

No offense, but I'm *so* glad it's not just me. I thought I was going insane.

It looks to me like the filter-generated file has some ffmpeg output prepended to it which is breaking things for some viewers (I don't use Quicktime and I don't have Nero, so I'm sort of stuck with WMP).

If I knew the code better I would check zmfilter.pl to see if it's writing the video-generation command to zmvideo.pl in addition to the output or ffmpeg. Almost like it starts piping output to zmvideo (or ffmpeg) too early, or it starts the command and then prints it again by mistake.

I'm waiting to see if Peter Howard's 1.23 has ffmpeg support, and if so I'm planning a reinstall on Ubuntu 7.10. Perhaps things will just start working again.

hvisser · Post by **hvisser** » Fri Jan 18, 2008 11:41 am

The following seems to have resolved my problem.

I saw a post a while back that stated:

Check in zmvideo.pl and change ">& ffmpeg.log" to "&> /tmp/ffmpeg.log"

PS: This is on line 323

I made that change last night and I suspected after that change it 'broke' the mpg's

I thought changing it back would fix it, but then it stopped sending all together and mpg's weren't being created.

Done some more searching this morning and found a post suggesting to remove the "&" so it looks like it should be change zmvideo.pl line 323

Code: Select all

">& ffmpeg.log"

to

Code: Select all

"> /tmp/ffmpeg.log"

Once again, don't know why, but for now it seems like it works. Not too good with Perl yet, but I'm learning slowly.

haus · Post by **haus** » Fri Jan 18, 2008 3:14 pm

[Post deleted]

hvisser · Post by **hvisser** » Fri Jan 18, 2008 6:42 pm

Sorry, but I think I jumped the gun. It worked for the first 3 or so, then started playing up again, now it makes now difference, despite reboot, etc.

Let me know what happens with yours.

haus · Post by **haus** » Fri Jan 18, 2008 6:49 pm

Ugh, sorry to hear that. I'll try to test it some more. So odd that this seems to work a few times and then get munged.

I was so pleased that it was working, too. You didn't change anything else, I assume, since you changed the >& line.

haus · Post by **haus** » Fri Jan 18, 2008 6:54 pm

Do you have extra debugging turned on? I think I'm on to something.

hvisser · Post by **hvisser** » Fri Jan 18, 2008 7:13 pm

Didn't make any other changes after removing the "&". Figured I would leave it and make a partimage of the "what I thought was working" system before fiddling with it again.

Totally bummed.

Don't have any debugging turned on. One thing I have noticed, if I delete the /tmp/ffmpeg.log file, it gets recreated when a new video is generated, but it is a zero byte file, i.e nothing gets logged to it.

One question. If you have %EV% in the body part of the email, can you take the tick out of "Create video for all matches" in the Filter? Would it still try to generate the video file on account of the %EV%? At the moment I have both.

haus · Post by **haus** » Fri Jan 18, 2008 7:31 pm

I thought I was onto something but it was a dead end.

I've tried disabling logging/debugging in FFMPEG in hopes that it wouldn't write that funny header info, but it doesn't help. I'm completely stumped; I don't know the code well enough to make this work. Obviously the clue that it works when you generate manually and fails when you use filters indicates either something is wrong with the way zmfilter.pl calls zmvideo.pl or something is wrong with the runtime environment when zmfilter.pl is running that is messing up ffmpeg.

I'm leaning toward the latter because I can't see any difference between the calls to zmvideo.pl (see my earlier message after Phil asked me to put in the logging into from both scripts - the commands are the same). It almost appears that when zmfilter.pl is running, there's a bit of a race condition with ffmpeg such that its stdout debug/logging info (ending with "press q to stop encoding) is being redirected to the output file instead of the log file (or the terminal).

I had %EV% in the email body and the "Create video" ticked at first; in a prior post I noted that I tried with just %EV% in the email and unticked the check box in the filter. ZM was smart enough to catch that the video already existed in the first case so it didn't create it again, and this problem still exists in either case for me.