blakeblackshear / frigate

NVR with realtime local object detection for IP cameras
https://frigate.video
MIT License
19.21k stars 1.76k forks source link

There were no cache files for this event #761

Closed wjcloudy closed 3 years ago

wjcloudy commented 3 years ago

Occasionally getting the following errors in logs and no clips created:

frigate.events WARNING : Unable to create clip for workshop and event 1612908365.904587-0a300m. There were no cache files for this event.

I use a the HQ stream URL for clips - but it does sometimes work. Anything I can do to help troubleshoot? I'm guessing the clips stream is not working or dropping out, but I can't see any way to check this... (I guess it's always streaming to manage the pre record)

blakeblackshear commented 3 years ago

You should have some log messages when the clips ffmpeg process exits and restarts. That should have some info on why it lost connection.

wjcloudy commented 3 years ago

There's a lot going on, but a lot of the errors seem related to messages below - I also notice some timeouts, is the extremely long timeout for a connection attempt correct? ffmpeg.drive.detect ERROR : [tcp @ 0x5609b8b9d280] Connection to tcp://x.x.x.x:554?timeout=5000000 failed: Connection timed out

frigate.video INFO : drive: ffmpeg sent a broken frame. memoryview assignment: lvalue and rvalue have different structures frigate.video INFO : drive: ffmpeg process is not running. exiting capture thread... ffmpeg.drive.detect ERROR : [rtsp @ 0x55f6bfbf8900] Error parsing AU headers

ffmpeg.drive.detect ERROR : Last message repeated 623507 times

ffmpeg.drive.clips_rtmp ERROR : [rtsp @ 0x565187fd4dc0] Error parsing AU headers

ffmpeg.drive.clips_rtmp ERROR : Last message repeated 83 times

ffmpeg.drive.clips_rtmp ERROR : [segment @ 0x565187ff7ec0] Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly

ffmpeg.drive.clips_rtmp ERROR : [flv @ 0x565187fde1c0] Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly

ffmpeg.drive.clips_rtmp ERROR : [segment @ 0x565187ff7ec0] Non-monotonous DTS in output stream 0:0; previous: 0, current: 0; changing to 1. This may result in incorrect timestamps in the output file.

ffmpeg.drive.clips_rtmp ERROR : [rtsp @ 0x565187fd4dc0] Error parsing AU headers

ffmpeg.drive.clips_rtmp ERROR : Last message repeated 623423 times

ffmpeg.drive.clips_rtmp ERROR : [flv @ 0x565187fde1c0] Failed to update header with correct duration.

ffmpeg.drive.clips_rtmp ERROR : [flv @ 0x565187fde1c0] Failed to update header with correct filesize.

wjcloudy commented 3 years ago

Also tried using the low quality (detect) stream for clips too - same issue, but the low quality stream must be working for the detector to pick up the event (and I can watch it in the web view whilst this happens)

It's not working on some cameras sometimes - even from a fresh start, with no obvious ffmpeg quits. I've also dropped pre and post clipping to 5 and 5 in case related to #662.

I also notice there is only one large cache clip for each camera, they are not being split - in case that isn't normal....

frigate.events DEBUG : Event received: start workshop 1612958815.602424-wr0a69 frigate.events DEBUG : Event received: start workshop 1612958820.967081-i3ap96 frigate.events DEBUG : Event received: end workshop 1612958815.602424-wr0a69 frigate.events DEBUG : No cache clips for workshop. Waiting... frigate.events DEBUG : No cache clips for workshop. Waiting... frigate.events DEBUG : No cache clips for workshop. Waiting... frigate.events DEBUG : No cache clips for workshop. Waiting... frigate.events DEBUG : No cache clips for workshop. Waiting... frigate.events DEBUG : No cache clips for workshop. Waiting... frigate.events DEBUG : No cache clips for workshop. Waiting... frigate.events WARNING : Unable to create clip for workshop and event 1612958815.602424-wr0a69. There were no cache files for this event.

blakeblackshear commented 3 years ago

Try switching your audio stream on the camera to AAC if you haven't already. You can also try removing the rtmp role if that doesn't work to see if it's the issue.

wjcloudy commented 3 years ago

No audio on these cameras, removing RTMP role also does not help...

How does frigate work out if there is a cache clip that covers the event? It seems to be dumping all segments onto the end of a single large cache file? The code seems to be expecting to cover the event with multiple clips - but I only ever have as single clip in the cache with a timestamp of the frigate container launch or the last wrap round (it overwrites?)

while len(sorted_clips) == 0 or sorted_clips[-1]['start_time'] + sorted_clips[-1]['duration'] < event_data['end_time']+post_capture:

It seems the event is covered by the recording in the clip cache but for some reason frigate is not seeing it...

blakeblackshear commented 3 years ago

Can you post your full config?

wjcloudy commented 3 years ago

detectors:
  coral:
    type: edgetpu
    device: usb

mqtt:
  host: xxxxxxx
  topic_prefix: frigate
  user: xxxxxxx
  password: "xxxxxxx"

logger:
  default: debug

clips:
  max_seconds: 300
  tmpfs_cache_size: 1G
  retain:
    default: 10

ffmpeg:
  global_args: -hide_banner -loglevel warning
  hwaccel_args: -hwaccel vaapi -hwaccel_device /dev/dri/renderD128 -hwaccel_output_format yuv420p
  input_args: -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -rtsp_transport tcp -stimeout 5000000 -use_wallclock_as_timestamps 1
  #input_args: -avoid_negative_ts make_zero -fflags nobuffer -flags low_delay -strict experimental -fflags +genpts+discardcorrupt -vsync drop -use_wallclock_as_timestamps 1

  output_args:
    detect: -f rawvideo -pix_fmt yuv420p
    record: -f segment -segment_time 60 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an
    clips: -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an
    rtmp: -c copy -f flv
objects:
  track:
    - person
    - car
    - dog
    - cat
  filters:
    person:
      min_area: 4000
      max_area: 100000
      threshold: 0.65

cameras:
  drive:
    ffmpeg:
      inputs:
        - path: rtsp://xxxxxxx:554/stream1
          roles:
            - detect
        - path: rtsp://xxxxxxx:554/stream0
          roles:
            #- rtmp
            - clips

    height: 576
    width: 704
    fps: 5
    clips:
      enabled: True
      pre_capture: 5
      post_capture: 5
      retain:
        default: 14
    snapshots:
      enabled: True
      timestamp: True
      bounding_box: True

    objects:
      track:
        - person
        - car
      filters:
        person:
          min_area: 500
          max_area: 100000
          threshold: 0.75
        car:
          min_area: 500
          max_area: 100000
          threshold: 0.75
          mask:
            - 704,201,704,576,0,576,0,330,370,311,424,197

  road:
    ffmpeg:
      inputs:
        - path: rtsp://xxxxxxx:554/stream2
          roles:
            - detect
        - path: rtsp://xxxxxxx:554/stream1
          roles:
            #- rtmp
            - clips
    clips:
      enabled: True
      pre_capture: 5
      post_capture: 5
      retain:
        default: 14
    height: 480
    width: 640
    fps: 10
    motion:
      delta_alpha: 0.3
    snapshots:
      enabled: True
      timestamp: True
      bounding_box: True
    objects:
      track:
        - person
        - car
      filters:
        person:
          min_area: 1000
          max_area: 100000
          threshold: 0.75
        car:
          min_area: 3000
          max_area: 100000
          threshold: 0.7

  house:
    ffmpeg:
      inputs:
        - path: rtsp://xxxxxxx:554/stream2
          roles:
            - detect
        - path: rtsp://xxxxxxx:554/stream1
          roles:
            #- rtmp
            - clips
    height: 480
    width: 640
    fps: 5
    motion:
      mask:
        - 0,158,0,0,640,0,640,258,640,350,640,480,363,480,512,342,521,326,524,121
    clips:
      enabled: True
      pre_capture: 5
      post_capture: 5
      retain:
        default: 14
    snapshots:
      enabled: True
      timestamp: True
      bounding_box: True
    objects:
      track:
        - person
        - car
        - dog
        - cat
      filters:
        person:
          min_area: 500
          max_area: 100000
          threshold: 0.7
        car:
          min_area: 500
          max_area: 100000
          threshold: 0.75
          mask:
            - 0,204,0,271,219,266,221,191

  workshop:
    ffmpeg:
      inputs:
        - path: rtsp:/xxxxxxx:554/stream2
          roles:
            - detect
        - path: rtsp://xxxxxxx:554/stream1
          roles:
            #- rtmp
            - clips
    height: 480
    width: 640
    fps: 5
    clips:
      enabled: True
      pre_capture: 5
      post_capture: 5
      retain:
        default: 14
    snapshots:
      enabled: True
      timestamp: True
      bounding_box: True
    objects:
      track:
        - person
      filters:
        person:
          min_area: 500
          max_area: 100000
          threshold: 0.65

  garage:
    ffmpeg:
      inputs:
        - path: rtsp://xxxxxxx:80/ch0_1.264
          roles:
            - detect
        - path: rtsp://xxxxxxx:80/ch0_0.264
          roles:
            #- rtmp
            - clips

    height: 360
    width: 640
    fps: 5
    clips:
      enabled: True
      pre_capture: 5
      post_capture: 5
      retain:
        default: 14
    snapshots:
      enabled: True
      timestamp: True
      bounding_box: True
    objects:
      track:
        - person
      filters:
        person:
          min_area: 500
          max_area: 100000
          threshold: 0.75

  garden:
    ffmpeg:
      inputs:
        - path: rtsp://xxxxxxx:554/stream2
          roles:
            - detect
        - path: rtsp://xxxxxx:554/stream1
          roles:
            #- rtmp
            - clips
    height: 480
    width: 640
    fps: 5
    clips:
      enabled: True
      pre_capture: 5
      post_capture: 5
      retain:
        default: 14
    motion:
      contour_area: 50
      delta_alpha: 0.6
      threshold: 15
      mask:
        - 0,480,640,480,640,364,640,265,640,0,588,0,574,170,463,148,76,217,101,91,263,54,285,0,0,0
        - 0,0,640,0,640,385,558,390,566,72,243,56,0,99
    snapshots:
      enabled: True
      timestamp: True
      bounding_box: True
    objects:
      track:
        - person
        - dog
        - cat
      filters:
        person:
          min_area: 500
          max_area: 100000
          threshold: 0.65
          mask:
            - 91,410,297,440,498,452,605,444,640,430,640,251,640,203,510,207
`
blakeblackshear commented 3 years ago

I only ever have as single clip in the cache with a timestamp of the frigate container launch or the last wrap round

This is exactly what happens when you have -vsync drop in your input args. I noticed you have those removed now. Are you still seeing that behavior? This is why there is this big banner warning in the docs. image

wjcloudy commented 3 years ago

I was testing with a previous version of my args from the last version just to confirm - it did (as you say) cause all clips to fail, and explains the cache single files - but I am still getting the issue every now and again without -vsync drop (issue occurs with the non commented line) I now have debug logging enabled, so will report on the logs the next event that fails...

colino17 commented 3 years ago

I'm getting the same issue. Clips were saving properly until this morning, but then all day today I was getting detections but no clips.

Logs have a bunch of these:

A bunch of these

ffmpeg.side_yard.clips         ERROR   : [segment @ 0x5604ed9cf0c0] Non-monotonous DTS in output stream 0:0; previous: 4794767936, current: 4794767936; changing to 4794767937. This may result in incorrect timestamps in the output file.

followed by a bunch of these:

ffmpeg.side_yard.clips         ERROR   : [flv @ 0x5604ed9c7b40] Packet mismatch 135183235 11 -857488686

and then

ffmpeg.side_yard.clips         ERROR   : [flv @ 0x5604ed9c7b40] Unable to seek to the next packet
ffmpeg.side_yard.clips         ERROR   : rtmp://192.168.1.100/bcs/channel0_main.bcs?channel=0&stream=0&user=user&password=password: Invalid data found when processing input
watchdog.side_yard             INFO    : Terminating the existing ffmpeg process...
watchdog.side_yard             INFO    : Waiting for ffmpeg to exit gracefully...
ffmpeg.side_yard.clips         ERROR   : [tcp @ 0x55d681562480] RTMP packet size mismatch 9200033 != 5327191
ffmpeg.side_yard.clips         ERROR   : rtmp://192.168.1.100/bcs/channel0_main.bcs?channel=0&stream=0&user=user&password=password: Input/output error
watchdog.side_yard             INFO    : Terminating the existing ffmpeg process...
watchdog.side_yard             INFO    : Waiting for ffmpeg to exit gracefully...
watchdog.side_yard             INFO    : No frames received from side_yard in 20 seconds. Exiting ffmpeg...
watchdog.side_yard             INFO    : Waiting for ffmpeg to exit gracefully...
frigate.video                  INFO    : side_yard: ffmpeg sent a broken frame. memoryview assignment: lvalue and rvalue have different structures
frigate.video                  INFO    : side_yard: ffmpeg process is not running. exiting capture thread...
ffmpeg.side_yard.detect        ERROR   : [flv @ 0x55eae7bd88c0] Packet mismatch 34573441 11 789447
ffmpeg.side_yard.detect        ERROR   : [flv @ 0x55eae7bd88c0] Packet mismatch 1398863006 131610 921057
ffmpeg.side_yard.detect        ERROR   : [flv @ 0x55eae7bd88c0] Packet mismatch 1662669957 131610 1052667
ffmpeg.side_yard.detect        ERROR   : [flv @ 0x55eae7bd88c0] Packet mismatch 7168 243738 1296405
ffmpeg.side_yard.detect        ERROR   : [flv @ 0x55eae7bd88c0] Packet mismatch 798846710 131610 1428015
ffmpeg.side_yard.detect        ERROR   : [flv @ 0x55eae7bd88c0] Unable to seek to the next packet
ffmpeg.side_yard.detect        ERROR   : rtmp://192.168.1.100/bcs/channel0_sub.bcs?channel=0&stream=0&user=user&password=password: Invalid data found when processing input
frigate.events                 WARNING : Unable to create clip for side_yard and event 1613042245.858785-4rlz35. There were no cache files for this event.

I've also noticed that I seem to get the "no cache files for this event" from the very start if I try to increase the "post_capture" above 5 seconds.

colino17 commented 3 years ago

Config is as follows:

mqtt:
  host: 192.168.1.88
  port: 1883
  topic_prefix: frigate
  client_id: frigate
  user: user

detectors:
  cpu:
    type: cpu

clips:
  retain:
    default: 10

objects:
  track:
    - Person
    - Animal

cameras:
  side_yard:
    ffmpeg:
      inputs:
        - path: rtmp://192.168.1.100/bcs/channel0_main.bcs?channel=0&stream=0&user=user&password=password
          roles:
            - clips
          input_args:
            - -avoid_negative_ts
            - make_zero
            - -fflags
            - nobuffer
            - -flags
            - low_delay
            - -strict
            - experimental
            - -fflags
            - +genpts+discardcorrupt
            - -rw_timeout
            - '5000000'
            - -use_wallclock_as_timestamps
            - '1' 
        - path: rtmp://192.168.1.100/bcs/channel0_sub.bcs?channel=0&stream=0&user=user&password=password
          roles:
            - detect
          input_args:
            - -avoid_negative_ts
            - make_zero
            - -fflags
            - nobuffer
            - -flags
            - low_delay
            - -strict
            - experimental
            - -fflags
            - +genpts+discardcorrupt
            - -rw_timeout
            - '5000000'
            - -use_wallclock_as_timestamps
            - '1'
    width: 640
    height: 480
    fps: 7
    detect:
      enabled: True
      max_disappeared: 10
    clips:
      enabled: True
    record:
      enabled: False
      retain_days: 3
    snapshots:
      enabled: True
      timestamp: False
      bounding_box: True
    mqtt:
      enabled: True
      timestamp: False
      bounding_box: True
    rtmp:
      enabled: False
blakeblackshear commented 3 years ago

It is odd that you are getting flv errors without rtmp enabled. That is usually where the flv messages come in. Can you also post the output of /api/config or the json config from the debug section of the web ui?

colino17 commented 3 years ago

Sure:

{
  "data": {
    "cameras": {
      "side_yard": {
        "best_image_timeout": 60,
        "clips": {
          "enabled": true,
          "objects": null,
          "post_capture": 5,
          "pre_capture": 5,
          "retain": {
            "default": 10,
            "objects": {}
          }
        },
        "detect": {
          "enabled": true,
          "max_disappeared": 10
        },
        "ffmpeg_cmds": [
          {
            "cmd": "ffmpeg -hide_banner -loglevel warning -avoid_negative_ts make_zero -fflags nobuffer -flags low_delay -strict experimental -fflags +genpts+discardcorrupt -rw_timeout 5000000 -use_wallclock_as_timestamps 1 -i rtmp://192.168.1.100/bcs/channel0_main.bcs?channel=0&stream=0&user=user&password=password -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /tmp/cache/side_yard-%Y%m%d%H%M%S.mp4",
            "roles": [
              "clips"
            ]
          },
          {
            "cmd": "ffmpeg -hide_banner -loglevel warning -avoid_negative_ts make_zero -fflags nobuffer -flags low_delay -strict experimental -fflags +genpts+discardcorrupt -rw_timeout 5000000 -use_wallclock_as_timestamps 1 -i rtmp://192.168.1.100/bcs/channel0_sub.bcs?channel=0&stream=0&user=user&password=password -r 7 -f rawvideo -pix_fmt yuv420p pipe:",
            "roles": [
              "detect"
            ]
          }
        ],
        "fps": 7,
        "frame_shape": [
          480,
          640
        ],
        "height": 480,
        "motion": {
          "contour_area": 100,
          "delta_alpha": 0.2,
          "frame_alpha": 0.2,
          "frame_height": 80,
          "mask": null,
          "threshold": 25
        },
        "mqtt": {
          "bounding_box": true,
          "crop": true,
          "enabled": true,
          "height": 270,
          "timestamp": false
        },
        "name": "side_yard",
        "objects": {
          "filters": {
            "Animal": {
              "mask": null,
              "max_area": 24000000,
              "min_area": 0,
              "min_score": 0.5,
              "threshold": 0.7
            },
            "Person": {
              "mask": null,
              "max_area": 24000000,
              "min_area": 0,
              "min_score": 0.5,
              "threshold": 0.7
            }
          },
          "track": [
            "Person",
            "Animal"
          ]
        },
        "record": {
          "enabled": false,
          "retain_days": 3
        },
        "rtmp": {
          "enabled": false
        },
        "snapshots": {
          "bounding_box": true,
          "crop": false,
          "enabled": true,
          "height": null,
          "retain": {
            "default": 10,
            "objects": {}
          },
          "timestamp": false
        },
        "width": 640,
        "zones": {}
      }
    },
    "clips": {
      "max_seconds": 300,
      "retain": {
        "default": 10,
        "objects": {}
      },
      "tmpfs_cache_size": ""
    },
    "database": {
      "path": "/media/frigate/clips/frigate.db"
    },
    "detectors": {
      "cpu": {
        "device": "usb",
        "num_threads": 3,
        "type": "cpu"
      }
    },
    "environment_vars": {},
    "logger": {
      "default": "INFO",
      "logs": {}
    },
    "model": {
      "height": 320,
      "width": 320
    },
    "mqtt": {
      "client_id": "frigate",
      "host": "192.168.1.88",
      "port": 1883,
      "stats_interval": 60,
      "topic_prefix": "frigate",
      "user": "user"
    },
    "snapshots": {
      "retain": {
        "default": 10,
        "objects": {}
      }
    }
  },
  "status": "loaded"
}
blakeblackshear commented 3 years ago

I'm surprised that you have flv related messages in your logs. They must be related to the rtmp inputs from your camera. My guess is that this is just an unreliable connection to your camera. Not sure what would have changed for you. You may want to try power cycling your cameras.

colino17 commented 3 years ago

The clip saving seems to be working after I rebooted my docker container. The camera is hardwired POE so theoretically it should be stable, but its hard to tell.

EDIT: Would RTSP be a better choice? I was using it before frigate 0.8 and didn't notice any issues. I switched after the upgrade because of the issue mentioned below while troubleshooting. RTMP seemed like the recommended option for Reolink cams in the docs.

My main confusion is over the cache issues that arise when I increase "post_capture". When that is increased I don't get any clips saved and get constant cache errors for every event. It seems like it's looking to pull the entire clip from cache before the event/post capture is over.

blakeblackshear commented 3 years ago

There is an edge case when post_capture is too large that causes frigate to give up on creating a clip. Not sure how much of an increase causes this or how I will fix it yet.

Would RTSP be a better choice? I was using it before frigate 0.8 and didn't notice any issues. I switched after the upgrade because of the issue mentioned below while troubleshooting. RTMP seemed like the recommended option for Reolink cams in the docs.

I don't know. Seems like most Reolink users are using RTMP. You can try and see if it works for you.

colino17 commented 3 years ago

I know in my case I tested 40s and it caused cache issue. I'll try to test different times and also the RTSP vs RTMP issue and report back.

Thanks for all your time and effort on this. Great project overall.

wjcloudy commented 3 years ago

Closing this issue as I believe this was caused by excessive post record lengths which is already being worked on - the issue hasn't happened since when using a 5 second post record and shorter keyframe gaps.

Morphy99 commented 3 years ago

I've encountered this issue with only 5s post capture. I've only been running RTMP for a couple of days as I had lots of smearing and stream corruption from my Reolink RLC-520 using RTSP. My clips stream is 2048x1536 30 fps. This hasn't occurred immediately, looking at the logs it occurred around 01:00 and the container was up since about 22:00.

blakeblackshear commented 3 years ago

Please open a new issue rather than commenting on old issues.

Morphy99 commented 3 years ago

I know in my case I tested 40s and it caused cache issue. I'll try to test different times and also the RTSP vs RTMP issue and report back.

Thanks for all your time and effort on this. Great project overall.

Did you establish what times caused an issue? I've just tried extending recording time to 30 and had the same problem with clips not being saved.

@blakeblackshear sorry, my issue appeared the same as this so I didn't want to duplicate. 15 days isn't that old either? Although I'm not sure if this went away, or I just haven't noticed it, as I've been playing so much with my config this issue fell by the wayside and I haven't encountered it until extending the post capture length just now. I'm guessing you opened a new issue under #788 so I'll keep an eye on that. Maybe worth a mention in the docs that this can cause issues over x amount of seconds if we can establish when this occurs. I'm happy to submit a PR for that if we can get a rough number, I'm OK with docs but that's as far as my skill set goes most of the time!