Further logs

fregatte · August 6, 2020, 4:37pm

Continuing the discussion from Amcrest question:

tnx; was not aware that

homeassistant.components.amcrest
and just
amcrest

are two different log entities.

Have set amcrest also to debug (tnx for the suggestion)

Query 7 seems to be the issue:

2020-08-06 18:04:31 DEBUG (SyncWorker_0) [homeassistant.components.amcrest.camera] Updating els_beik_215 camera
2020-08-06 18:04:31 DEBUG (SyncWorker_0) [amcrest.http] None:None Trying Basic Authentication
2020-08-06 18:04:31 DEBUG (SyncWorker_0) [amcrest.http] None:None HTTP query 1: http://192.168.2.215:80/cgi-bin/magicBox.cgi?action=getMachineName
2020-08-06 18:04:31 DEBUG (SyncWorker_0) [amcrest.http] None:None Running query 1 attempt 1
2020-08-06 18:04:31 DEBUG (SyncWorker_0) [amcrest.http] None:None Query 1: Unauthorized (401)
2020-08-06 18:04:31 DEBUG (SyncWorker_0) [amcrest.http] None:None Trying Digest Authentication
2020-08-06 18:04:31 DEBUG (SyncWorker_0) [amcrest.http] None:None HTTP query 2: http://192.168.2.215:80/cgi-bin/magicBox.cgi?action=getMachineName
2020-08-06 18:04:31 DEBUG (SyncWorker_0) [amcrest.http] None:None Running query 2 attempt 1
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:None> Query 2 worked. Exit code: <200>
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:None> Retrieving serial number
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:None> HTTP query 3: http://192.168.2.215:80/cgi-bin/magicBox.cgi?action=getSerialNo
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:None> Running query 3 attempt 1
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Query 3 worked. Exit code: <200>
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> HTTP query 4: http://192.168.2.215:80/cgi-bin/magicBox.cgi?action=getVendor
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Running query 4 attempt 1
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Query 4 worked. Exit code: <200>
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> HTTP query 5: http://192.168.2.215:80/cgi-bin/magicBox.cgi?action=getDeviceType
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Running query 5 attempt 1
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Query 5 worked. Exit code: <200>
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> HTTP query 6: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=Encode
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Running query 6 attempt 1
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Query 6 worked. Exit code: <200>
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> HTTP query 7: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Running query 7 attempt 1
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> **Query 7 failed due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.215:80/cgi-bin/configManager.cgi?**action=getConfig&name=RecordMode’)
2020-08-06 18:04:32 WARNING (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Trying again due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode’)
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Running query 7 attempt 2
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Query 7 failed due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode’)
2020-08-06 18:04:32 DEBUG (SyncWorker_0) [homeassistant.components.amcrest] els_beik_215 camera errs: 1
2020-08-06 18:04:32 ERROR (SyncWorker_0) [homeassistant.components.amcrest.camera] Could not get els_beik_215 camera attributes due to error: CommError

with another camera (same brand/model/firmware)
Query 7 is fine:

2020-08-06 18:04:32 DEBUG (SyncWorker_5) [homeassistant.components.amcrest] els_1og_220 camera errs: 1
2020-08-06 18:04:32 ERROR (SyncWorker_5) [homeassistant.components.amcrest.camera] Could not get els_1og_220 camera attributes due to error: CommError
2020-08-06 18:04:32 DEBUG (SyncWorker_2) [homeassistant.components.amcrest.camera] Updating els_liv_ki_225 camera
2020-08-06 18:04:32 DEBUG (SyncWorker_2) [amcrest.http] None:None Trying Basic Authentication
2020-08-06 18:04:32 DEBUG (SyncWorker_2) [amcrest.http] None:None HTTP query 1: http://192.168.2.225:80/cgi-bin/magicBox.cgi?action=getMachineName
2020-08-06 18:04:32 DEBUG (SyncWorker_2) [amcrest.http] None:None Running query 1 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] None:None Query 1: Unauthorized (401)
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] None:None Trying Digest Authentication
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] None:None HTTP query 2: http://192.168.2.225:80/cgi-bin/magicBox.cgi?action=getMachineName
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] None:None Running query 2 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:None> Query 2 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:None> Retrieving serial number
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:None> HTTP query 3: http://192.168.2.225:80/cgi-bin/magicBox.cgi?action=getSerialNo
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:None> Running query 3 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 3 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 4: http://192.168.2.225:80/cgi-bin/magicBox.cgi?action=getVendor
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 4 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 4 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 5: http://192.168.2.225:80/cgi-bin/magicBox.cgi?action=getDeviceType
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 5 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 5 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 6: http://192.168.2.225:80/cgi-bin/configManager.cgi?action=getConfig&name=Encode
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 6 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 6 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 7: http://192.168.2.225:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 7 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 7 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 8: http://192.168.2.225:80/cgi-bin/configManager.cgi?action=getConfig&name=MotionDetect
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 8 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 8 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 9: http://192.168.2.225:80/cgi-bin/configManager.cgi?action=getConfig&name=Encode
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 9 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 9 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 10: http://192.168.2.225:80/cgi-bin/configManager.cgi?action=getConfig&name=MotionDetect
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 10 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 10 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 11: http://192.168.2.225:80/cgi-bin/configManager.cgi?action=getConfig&name=VideoInOptions
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 11 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 11 worked. Exit code: <200>
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> HTTP query 12: http://192.168.2.225:80/cgi-bin/configManager.cgi?action=getConfig&name=RTSP
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Running query 12 attempt 1
2020-08-06 18:04:33 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0017:2J0225PZA9A0017> Query 12 worked. Exit code: <200>

issue with ip 192.168.2.220 as well:
2020-08-06 18:05:17 DEBUG (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> HTTP query 12: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=Encode
2020-08-06 18:05:17 DEBUG (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Running query 12 attempt 1
2020-08-06 18:05:18 DEBUG (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Query 12 worked. Exit code: <200>
2020-08-06 18:05:18 DEBUG (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> HTTP query 13: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode
2020-08-06 18:05:18 DEBUG (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Running query 13 attempt 1
2020-08-06 18:05:18 DEBUG (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Query 13 failed due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode’)
2020-08-06 18:05:18 WARNING (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Trying again due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode’)
2020-08-06 18:05:18 DEBUG (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Running query 13 attempt 2
2020-08-06 18:05:18 DEBUG (SyncWorker_5) [amcrest.http] <2J0225PZA9A0014:2J0225PZA9A0014> Query 13 failed due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.215:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode’)
2020-08-06 18:05:18 DEBUG (SyncWorker_5) [homeassistant.components.amcrest] els_beik_215 camera errs: 1
2020-08-06 18:05:18 ERROR (SyncWorker_5) [homeassistant.components.amcrest.camera] Could not get els_beik_215 camera attributes due to error: CommError
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [homeassistant.components.amcrest.camera] Updating els_1og_220 camera
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> HTTP query 12: http://192.168.2.220:80/cgi-bin/configManager.cgi?action=getConfig&name=Encode
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> Running query 12 attempt 1
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> Query 12 worked. Exit code: <200>
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> HTTP query 13: http://192.168.2.220:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> Running query 13 attempt 1
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> Query 13 failed due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.220:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode’)
2020-08-06 18:05:18 WARNING (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> Trying again due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.220:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode’)
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> Running query 13 attempt 2
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [amcrest.http] <2J0225PZA9A0019:2J0225PZA9A0019> Query 13 failed due to error: HTTPError(‘403 Client Error: Forbidden for url: http://192.168.2.220:80/cgi-bin/configManager.cgi?action=getConfig&name=RecordMode’)
2020-08-06 18:05:18 DEBUG (SyncWorker_2) [homeassistant.components.amcrest] els_1og_220 camera errs: 1
2020-08-06 18:05:18 ERROR (SyncWorker_2) [homeassistant.components.amcrest.camera] Could not get els_1og_220 camera attributes due to error: CommError

strange, need to check further (as far as I can check from my user perspective)

pnbruckner · August 6, 2020, 5:08pm

Please format the log messages, just like you would do with YAML code. It’s kind of hard to read as is.

fregatte · August 6, 2020, 7:34pm

You are right; sorry; as I copied the log to a basich ascii txt editor and deleted the log entries not related to the issue the formatting is unfortunately gone; but no need to dig deep in this log; thanks to your support I figured out that just a couple of cams (all similar in terms of brand/model and firmware) are causing the log entries; so my next step is to factory restore one faulty and restore the configuration of one working into the faulty one and see the outcome.

fregatte · August 6, 2020, 10:53pm

seems to be I have got a solution (thanks to your hint/tip with the 2nd debug entry.

I have setup a user for HA access on my cams and not in all profiles on all cams I granted full admin rights.

I have done it for now and all is perfect now!

That is why curl in terminal was without error (user was admin there) and in HA there was this error persistent.

Thanks for your brilliant support and quick response!!

fregatte