search

kerberos-io / kerberos-docker

Run Kerberos Open Source inside a docker container.
http://doc.kerberos.io/opensource/installation#docker
103 stars 31 forks source link

Abnormal CPU load #27

Open drthanwho opened 4 years ago

drthanwho commented 4 years ago

Hey, I'm running Kerberos on docker on a Rpi3b. Usually it idles around 10-20%, apart from occasions when other processes are running. But it looks like every so often it goes above 40% and stays at that percentage until I restart the container. image image

cedricve commented 4 years ago

Can you check what the logs are saying at 2:00? It looks there is the peak.

On 21 May 2020, at 14:58, Thanasis notifications@github.com wrote:

Hey, I'm running Kerberos on docker on a Rpi3b. Usually it idles around 10-20%, apart from occasions when other processes are running. But it looks like every so often it goes above 40% and stays at that percentage until I restart the container. https://user-images.githubusercontent.com/22405505/82561146-260aae80-9b73-11ea-9ac8-5e9c3864358b.png https://user-images.githubusercontent.com/22405505/82561264-5eaa8800-9b73-11ea-8da6-a2a6444233ab.png — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/kerberos-io/docker/issues/27, or unsubscribe https://github.com/notifications/unsubscribe-auth/AALZUGZG6H26YQVCAOIE5HLRSUQPTANCNFSM4NG2EIWA.

drthanwho commented 4 years ago

For the sake of simplicity I've removed all repetitive lines of frame rate being too high. I was aware of that but didn't think it would be the cause of this cpu getting stuck that high.

21/05/2020 02:19:24.991 INFO  [trivial] IoVideo: end writing images
21/05/2020 02:19:24.999 INFO  [trivial] IoVideo: remove videowriter
21/05/2020 02:19:24.999 INFO  [trivial] IoVideo: unlocking write thread
21/05/2020 02:19:25.121 INFO  [trivial] IoVideo: closing capture thread
21/05/2020 02:19:55.279 INFO  [trivial] HullExpositor: activity detected from (577,457) to (686,505)
21/05/2020 02:19:55.280 INFO  [trivial] Heuristic is valid; numberOfChanges: 103, Sequence duration: 2
21/05/2020 02:19:55.280 INFO  [trivial] IoVideo: firing
21/05/2020 02:19:55.380 INFO  [trivial] IoVideo: start new recording 1590027595_6-280491_Eisodos_577-457-686-505_103_356.mp4
21/05/2020 02:19:55.464 INFO  [trivial] IoVideo (OpenCV): start writing images
21/05/2020 02:19:55.464 INFO  [trivial] IoVideo: locked write thread
21/05/2020 02:19:55.689 INFO  [trivial] IoVideo: initializing capture thread
21/05/2020 02:19:56.275 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
[...]
21/05/2020 02:19:58.555 INFO  [trivial] Executing IO devices for 2 detection(s)
21/05/2020 02:19:58.555 INFO  [trivial] IoMQTT: sending message...sent
21/05/2020 02:19:58.648 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
21/05/2020 02:19:58.739 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
21/05/2020 02:19:58.883 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
21/05/2020 02:19:59.047 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
21/05/2020 02:19:59.057 INFO  [trivial] IoMQTT: sending message...sent
21/05/2020 02:19:59.136 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
[...]
21/05/2020 02:20:10.347 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
21/05/2020 02:20:10.347 INFO  [trivial] IoVideo: end writing images
21/05/2020 02:20:10.361 INFO  [trivial] IoVideo: remove videowriter
21/05/2020 02:20:10.361 INFO  [trivial] IoVideo: unlocking write thread
21/05/2020 02:20:10.361 INFO  [trivial] IoVideo: remove videowriter
21/05/2020 02:20:10.361 INFO  [trivial] IoVideo: unlocking write thread
21/05/2020 02:20:10.392 INFO  [trivial] IoVideo: closing capture thread
21/05/2020 02:36:50.424 INFO  [trivial] HullExpositor: activity detected from (547,457) to (732,601)
21/05/2020 02:36:50.608 INFO  [trivial] HullExpositor: activity detected from (704,491) to (729,524)
21/05/2020 02:36:50.799 INFO  [trivial] HullExpositor: activity detected from (665,458) to (730,555)
21/05/2020 02:36:51.024 INFO  [trivial] HullExpositor: activity detected from (430,410) to (658,529)
21/05/2020 02:36:51.025 INFO  [trivial] Heuristic is valid; numberOfChanges: 194, Sequence duration: 2
21/05/2020 02:36:51.025 INFO  [trivial] IoVideo: firing
21/05/2020 02:36:51.132 INFO  [trivial] IoVideo: start new recording 1590028611_5-25628_Eisodos_430-410-658-529_194_494.mp4
21/05/2020 02:36:51.219 INFO  [trivial] IoVideo (OpenCV): start writing images
21/05/2020 02:36:51.219 INFO  [trivial] IoVideo: locked write thread
21/05/2020 02:36:51.424 INFO  [trivial] IoVideo: initializing capture thread
21/05/2020 02:36:51.454 INFO  [trivial] HullExpositor: activity detected from (433,175) to (681,528)
21/05/2020 02:36:51.454 INFO  [trivial] Heuristic is valid; numberOfChanges: 279, Sequence duration: 2
21/05/2020 02:36:51.500 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
21/05/2020 02:36:51.584 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
21/05/2020 02:36:51.688 INFO  [trivial] Executing IO devices for 2 detection(s)
21/05/2020 02:36:51.689 INFO  [trivial] IoMQTT: sending message...sent
21/05/2020 02:36:51.689 INFO  [trivial] IoScript: calling script at /etc/opt/kerberosio/scripts/run.sh
21/05/2020 02:36:51.713 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
21/05/2020 02:36:51.770 INFO  [trivial] HullExpositor: activity detected from (467,177) to (638,480)
21/05/2020 02:36:51.770 INFO  [trivial] Heuristic is valid; numberOfChanges: 64, Sequence duration: 2
21/05/2020 02:36:51.844 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
[..]
21/05/2020 02:36:58.900 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
cedricve commented 4 years ago

I assume it is normal as it started recording @drthanwho ?

drthanwho commented 4 years ago

This is over the last 7 days. Unfortunately the time axis is't labelled but here's the general idea. Peaks to 80% happen every day at 6am/2pm/9pm but are expected (a cron job running an ffmpeg timelapse script). The lowest periods (~6%) are midnight onwards (assume since there's no motion at night) and then day time it gets to ~10% and small peaks in those times must be the recordings. But since 8pm today looks like it's up to 30-40% and stuck there. image

Also this is of the last few hours image

I can't get to the logs right now but I'll check tomorrow and see what they say for 7:50pm

cedricve commented 4 years ago

Do you also have a memory dump?

Kind regards, Verstraeten Cédric

On 31 May 2020, at 23:59, Thanasis notifications@github.com wrote:

 These is over the last 7 days, Unfortunately the time axis is't labelled but here's the general idea. Peaks to 80% happen every day at 6am/2pm/9pm but are expected (a cron job running an ffmpeg timelapse script). The lowest periods (~6%) are midnight onwards (assume since there's no motion at night) and then day time it gets to ~10% and small peaks in those times must be the recordings. But since 8pm today looks like it's up to 30-40% and stuck there.

Also this is of the last few hours

I can't get to the logs right now but I'll check tomorrow and see what they say for 7:50pm

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

drthanwho commented 4 years ago

I don't know how to do that on the pi. If you can point me somewhere I could give it a try.

I've had a look on the logs but I can't find anything. If anything, there is weirdly nothing logged at the point where CPU starts going up.

These are from the point from yesterday's graph (~7.50pm)

30/05/2020 18:41:24.733 INFO  [trivial] HullExpositor: activity detected from (637,46) to (658,68)
30/05/2020 18:41:25.765 INFO  [trivial] Executing IO devices for 2 detection(s)
30/05/2020 18:41:25.765 INFO  [trivial] IoMQTT: sending message...sent
30/05/2020 18:41:25.969 INFO  [trivial] HullExpositor: activity detected from (635,58) to (655,78)
30/05/2020 18:41:26.267 INFO  [trivial] IoMQTT: sending message...sent
30/05/2020 18:41:26.437 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
30/05/2020 18:41:34.841 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
30/05/2020 18:41:37.138 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
30/05/2020 18:41:37.496 INFO  [trivial] IoVideo: end writing images
30/05/2020 18:41:37.501 INFO  [trivial] IoVideo: remove videowriter
30/05/2020 18:41:37.501 INFO  [trivial] IoVideo: unlocking write thread
30/05/2020 18:41:39.356 INFO  [trivial] IoVideo: closing capture thread
30/05/2020 18:57:34.545 INFO  [trivial] HullExpositor: activity detected from (571,120) to (608,143)
30/05/2020 21:49:34.073 INFO  [trivial] HullExpositor: activity detected from (485,44) to (727,604)
31/05/2020 02:27:18.082 INFO  [trivial] HullExpositor: activity detected from (553,35) to (683,154)
31/05/2020 02:27:20.373 INFO  [trivial] HullExpositor: activity detected from (574,50) to (630,160)
31/05/2020 02:27:20.373 INFO  [trivial] Heuristic is valid; numberOfChanges: 236, Sequence duration: 2
31/05/2020 02:27:20.373 INFO  [trivial] IoVideo: firing
31/05/2020 02:27:22.644 INFO  [trivial] IoVideo: start new recording 1590892040_6-373864_Eisodos_574-50-630-160_236_110.mp4
31/05/2020 02:27:22.719 INFO  [trivial] IoVideo (OpenCV): start writing images
31/05/2020 02:27:22.719 INFO  [trivial] IoVideo: locked write thread
31/05/2020 02:27:22.748 INFO  [trivial] Executing IO devices for 1 detection(s)
31/05/2020 02:27:22.748 INFO  [trivial] IoMQTT: sending message...sent
31/05/2020 02:27:22.748 INFO  [trivial] IoScript: calling script at /etc/opt/kerberosio/scripts/run.sh

And these are from today. It's happened again (should be ~9.30pm) image But I don't see anything logged past 9pm..

01/06/2020 20:51:25.052 INFO  [trivial] Executing IO devices for 2 detection(s)
01/06/2020 20:51:25.052 INFO  [trivial] IoMQTT: sending message...sent
01/06/2020 20:51:25.553 INFO  [trivial] IoMQTT: sending message...sent
01/06/2020 20:51:26.889 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
01/06/2020 20:51:29.330 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
01/06/2020 20:51:32.051 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
01/06/2020 20:51:32.202 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
01/06/2020 20:51:32.279 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
01/06/2020 20:51:32.852 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
01/06/2020 20:51:34.443 INFO  [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS)
01/06/2020 20:51:36.748 INFO  [trivial] IoVideo: end writing images
01/06/2020 20:51:36.761 INFO  [trivial] IoVideo: remove videowriter
01/06/2020 20:51:36.762 INFO  [trivial] IoVideo: unlocking write thread
01/06/2020 20:51:36.763 INFO  [trivial] IoVideo: closing capture thread
01/06/2020 22:31:20.316 INFO  [trivial] HullExpositor: activity detected from (640,47) to (660,68)
01/06/2020 22:31:21.475 INFO  [trivial] HullExpositor: activity detected from (554,38) to (672,148)
01/06/2020 22:31:21.632 INFO  [trivial] HullExpositor: activity detected from (445,454) to (731,615)
01/06/2020 22:31:21.632 INFO  [trivial] Heuristic is valid; numberOfChanges: 163, Sequence duration: 2
01/06/2020 22:31:21.632 INFO  [trivial] IoVideo: firing
01/06/2020 22:31:21.716 INFO  [trivial] IoVideo: start new recording 1591050681_6-633078_Eisodos_445-454-731-615_163_771.mp4
01/06/2020 22:31:21.777 INFO  [trivial] IoVideo (OpenCV): start writing images
01/06/2020 22:31:21.777 INFO  [trivial] IoVideo: locked write thread
01/06/2020 22:31:21.859 INFO  [trivial] IoVideo: initializing capture thread
01/06/2020 22:31:21.916 INFO  [trivial] Executing IO devices for 1 detection(s)
01/06/2020 22:31:21.916 INFO  [trivial] IoMQTT: sending message...sent
01/06/2020 22:31:21.916 INFO  [trivial] IoScript: calling script at /etc/opt/kerberosio/scripts/run.sh
cedricve commented 4 years ago

Did you tried to disable your script? Just to rule out some parts, and see if it also happens?

Kind regards, Verstraeten Cédric

On 2 Jun 2020, at 01:46, Thanasis notifications@github.com wrote:

 I don't know how to do that on the pi. If you can point me somewhere I could give it a try.

I've had a look on the logs but I can't find anything. If anything, there is weirdly nothing logged at the point where CPU starts going up.

These are from the point from yesterday's graph (~7.50pm)

30/05/2020 18:41:24.733 INFO [trivial] HullExpositor: activity detected from (637,46) to (658,68) 30/05/2020 18:41:25.765 INFO [trivial] Executing IO devices for 2 detection(s) 30/05/2020 18:41:25.765 INFO [trivial] IoMQTT: sending message...sent 30/05/2020 18:41:25.969 INFO [trivial] HullExpositor: activity detected from (635,58) to (655,78) 30/05/2020 18:41:26.267 INFO [trivial] IoMQTT: sending message...sent 30/05/2020 18:41:26.437 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 30/05/2020 18:41:34.841 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 30/05/2020 18:41:37.138 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 30/05/2020 18:41:37.496 INFO [trivial] IoVideo: end writing images 30/05/2020 18:41:37.501 INFO [trivial] IoVideo: remove videowriter 30/05/2020 18:41:37.501 INFO [trivial] IoVideo: unlocking write thread 30/05/2020 18:41:39.356 INFO [trivial] IoVideo: closing capture thread 30/05/2020 18:57:34.545 INFO [trivial] HullExpositor: activity detected from (571,120) to (608,143) 30/05/2020 21:49:34.073 INFO [trivial] HullExpositor: activity detected from (485,44) to (727,604) 31/05/2020 02:27:18.082 INFO [trivial] HullExpositor: activity detected from (553,35) to (683,154) 31/05/2020 02:27:20.373 INFO [trivial] HullExpositor: activity detected from (574,50) to (630,160) 31/05/2020 02:27:20.373 INFO [trivial] Heuristic is valid; numberOfChanges: 236, Sequence duration: 2 31/05/2020 02:27:20.373 INFO [trivial] IoVideo: firing 31/05/2020 02:27:22.644 INFO [trivial] IoVideo: start new recording 1590892040_6-373864_Eisodos_574-50-630-160_236_110.mp4 31/05/2020 02:27:22.719 INFO [trivial] IoVideo (OpenCV): start writing images 31/05/2020 02:27:22.719 INFO [trivial] IoVideo: locked write thread 31/05/2020 02:27:22.748 INFO [trivial] Executing IO devices for 1 detection(s) 31/05/2020 02:27:22.748 INFO [trivial] IoMQTT: sending message...sent 31/05/2020 02:27:22.748 INFO [trivial] IoScript: calling script at /etc/opt/kerberosio/scripts/run.sh And these are from today. It's happened again (should be ~9.30pm)

But I don't see anything logged past 9pm..

01/06/2020 20:51:25.052 INFO [trivial] Executing IO devices for 2 detection(s) 01/06/2020 20:51:25.052 INFO [trivial] IoMQTT: sending message...sent 01/06/2020 20:51:25.553 INFO [trivial] IoMQTT: sending message...sent 01/06/2020 20:51:26.889 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 01/06/2020 20:51:29.330 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 01/06/2020 20:51:32.051 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 01/06/2020 20:51:32.202 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 01/06/2020 20:51:32.279 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 01/06/2020 20:51:32.852 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 01/06/2020 20:51:34.443 INFO [trivial] IoVideo: framerate is too fast, can't record video at this speed (14/FPS) 01/06/2020 20:51:36.748 INFO [trivial] IoVideo: end writing images 01/06/2020 20:51:36.761 INFO [trivial] IoVideo: remove videowriter 01/06/2020 20:51:36.762 INFO [trivial] IoVideo: unlocking write thread 01/06/2020 20:51:36.763 INFO [trivial] IoVideo: closing capture thread 01/06/2020 22:31:20.316 INFO [trivial] HullExpositor: activity detected from (640,47) to (660,68) 01/06/2020 22:31:21.475 INFO [trivial] HullExpositor: activity detected from (554,38) to (672,148) 01/06/2020 22:31:21.632 INFO [trivial] HullExpositor: activity detected from (445,454) to (731,615) 01/06/2020 22:31:21.632 INFO [trivial] Heuristic is valid; numberOfChanges: 163, Sequence duration: 2 01/06/2020 22:31:21.632 INFO [trivial] IoVideo: firing 01/06/2020 22:31:21.716 INFO [trivial] IoVideo: start new recording 1591050681_6-633078_Eisodos_445-454-731-615_163_771.mp4 01/06/2020 22:31:21.777 INFO [trivial] IoVideo (OpenCV): start writing images 01/06/2020 22:31:21.777 INFO [trivial] IoVideo: locked write thread 01/06/2020 22:31:21.859 INFO [trivial] IoVideo: initializing capture thread 01/06/2020 22:31:21.916 INFO [trivial] Executing IO devices for 1 detection(s) 01/06/2020 22:31:21.916 INFO [trivial] IoMQTT: sending message...sent 01/06/2020 22:31:21.916 INFO [trivial] IoScript: calling script at /etc/opt/kerberosio/scripts/run.sh — You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.