BUG: Netcam gives "Error reading image header" occasionally

For over 1 year I have been noticing my netcam (D-Link DCS-900) causes Motion to log an error "Error reading image header" once every few hours.

Example:

Feb 24 04:48:29 mythserver motion: [1] Error reading image header
Feb 24 06:26:09 mythserver motion: [1] Error reading image header
Feb 24 09:09:09 mythserver motion: [1] Error reading image header
Feb 25 00:32:36 mythserver motion: [1] Error reading image header
Feb 25 02:09:37 mythserver motion: [1] Error reading image header
Feb 25 03:46:09 mythserver motion: [1] Error reading image header
Feb 25 05:21:16 mythserver motion: [1] Error reading image header
Feb 25 07:17:03 mythserver motion: [1] Error reading image header
Feb 25 10:04:25 mythserver motion: [1] Error reading image header

There is not a constant number of seconds between the 2am, 3am and 5am occurrences, being 5192 and 6307 seconds respectively.

JeffGroves has also noticed this occurring, it showed up in his log posted in my HTTP Keep-Alive thread - see FeatureRequest2007x01x22x231542 I didn't know what it was at that time, but I did think I'd better look into it.

My ffmpeg is built from source, with the following info: (though I don't think this is related)

FFmpeg version SVN-r11862
  libavutil version: 49.6.0
  libavcodec version: 51.50.0
  libavformat version: 52.7.0
  libavdevice version: 52.0.0
  built on Feb  4 2008 14:08:25

So far in my investigation, I have added a test-patch to output what Motion has in the header buffer at the time of the error. That provides the following output:

Feb 26 17:22:30 mythserver acpid: 1 client rule loaded
Feb 26 18:08:09 mythserver motion: [1] Error reading image header (1)
Feb 26 18:08:09 mythserver motion: [1] Erroneous header was ''#030''
Feb 26 19:25:29 mythserver motion: [1] Error reading image header (1)
Feb 26 19:25:29 mythserver motion: [1] Erroneous header was ''°P#010`#002)#010¸â(#010''
Feb 26 20:45:25 mythserver motion: [1] Error reading image header (1)
Feb 26 20:45:25 mythserver motion: [1] Erroneous header was ''¸#034+°`#002)#010¸â(#010''
Feb 26 22:02:04 mythserver motion: [1] Error reading image header (1)
Feb 26 22:02:04 mythserver motion: [1] Erroneous header was ''`÷¯`#002)#010¸â(#010''
Feb 26 23:23:43 mythserver motion: [1] Error reading image header (1)
Feb 26 23:23:43 mythserver motion: [1] Erroneous header was ''8÷¯`#002)#010¸â(#010''
Feb 27 00:48:36 mythserver motion: [1] Error reading image header (1)
Feb 27 00:48:36 mythserver motion: [1] Erroneous header was ''b+#010`#002)#010¸â(#010''
Feb 27 02:13:56 mythserver motion: [1] Error reading image header (1)
Feb 27 02:13:56 mythserver motion: [1] Erroneous header was ''8,l#010`#002)#010¸â(#010''
Feb 27 03:39:12 mythserver motion: [1] Error reading image header (1)
Feb 27 03:39:12 mythserver motion: [1] Erroneous header was ''ëD#010`#002)#010¸â(#010''
Feb 27 05:01:50 mythserver motion: [1] Error reading image header (1)
Feb 27 05:01:50 mythserver motion: [1] Erroneous header was ''°P#010`#002)#010¸â(#010''
Feb 27 06:25:30 mythserver motion: [1] Error reading image header (1)
Feb 27 06:25:30 mythserver motion: [1] Erroneous header was ''#004ð¯`#002)#010¸â(#010''
Feb 27 09:02:07 mythserver motion: [1] Error reading image header (1)
Feb 27 09:02:07 mythserver motion: [1] Erroneous header was ''°P#010`#002)#010¸â(#010''

Environment

Motion version:	SVN 310
ffmpeg version:	SVN 11862
Shared libraries:	ffmpeg
Server OS:	Fedora Core 8

-- SimonW - 27 Feb 2008

Follow up

I'm quite happy to work on this on my own, although it might affect users of other streaming netcams - which I can't test as I don't have any other. I have an Aviosys IP9100A but that is not a streaming type.

I think the goal for a patch to detect and silently discard any 'garbage' headers returned from a netcam, removing the current log entries that we see occasionally. If Motion is in Debug mode, we should still informing the user with a log entry.

So we need to work out a condition statement to allow Motion to discard the garbage header data - without ever discarding a real header, one which may not be understood by Motion at present.

Looking at the contents of the garbage header, it might be part of a MJPEG image which is continuing longer than the length supplied in the header (which is what Motion would work to). I don't actually know what MJPEG image data looks like, if it contains binary (non-printing) characters or not.

Currently the best way I can think of to detect the 'garbage' headers would be to detect any non-printable character (in the output above we have #010, #002, #030, #034).

This would be done by using the isprint() function. If the entire header buffer is scanned using a loop, testing each character with isprint(), and any of them give isprint()==0 (ie. they are non-printing characters) then we could set a flag True.

If, once the entire header line has been checked, the flag is True, then that line is discarded, perhaps with a log entry (only if in a Debug mode - perhaps?).

This would seem to achieve the goal, what do others think?

-- SimonW - 27 Feb 2008

I think you are on the right track.

First you are right that Motion should not flood the logs unless in debug mode. The logs should help finding out why Motion will not work but not be flooding on occational errors.

You can never trust external sources and for sure some cameras are plain buggy or the network sometimes has "glitches". If a network camera normally works and recovers by simply skipping a picture frame then it should do that. If the entire picture is garbage (mjpeg is just a stream of plain jpegs separated by a simple header) I assume this get caught later in the process when trying to decode the image with the jpeg lib functions.

-- KennethLavrsen - 07 Mar 2008

Fix record

Hi again,

After a bit of investigation I have found out more. The 'unknown' headers are not garbage (I had a bad pointer reference) but are like this:

Apr 11 16:20:34 mythserver motion: [1] Error reading image header (1). Unknown header '--video boundary--#015'
Apr 12 07:28:39 mythserver motion: [1] Error reading image header (1). Unknown header '--video boundary--#015'
Apr 12 09:17:07 mythserver motion: [1] Error reading image header (1). Unknown header '--video boundary--#015'
Apr 12 19:17:41 mythserver motion: [1] Error reading image header (1). Unknown header '--video boundary--#015'

Looks like my netcam (D-Link DCS-900) just gets it wrong once in a while, transmitting one extra character at the end of the video boundary. It is running 24/7 at 5fps so that's a lot of frames between errors.

I have a patch which just requires a bit of finishing, then I will post it.

Simon.

-- SimonW - 16 Apr 2008

Attached is the patch "SWpatch_IllegalHeaders_20080416" which will suppress 'Error reading image header' unless Motion is in debug mode. There's a second reason why that message may be seen, but there is no change in that, as I have not observed it ever occurring on my system.

It does seem a little strange to suppress an error message, but assuming that your Netcam is giving images, an error every now and then (which will never go away) is cluttering the log. If a netcam gives no images at all, of course the correct course of action is to run in debug mode and inspect the messages to see what is wrong.

-- SimonW - 16 Apr 2008

---

Thanks Simon, committed to trunk and 3.2.10

-- AngelCarpintero - 17 Apr 2008

---

This is fixed in 3.2.11 branch

-- AngelCarpintero - 07 Aug 2008