Amcrest question

I have a new Amcrest camera (IP8M-2496E), my other amcrest cameras (IP3M-941) work fine, but for some reason this one is just not cooperating. I did note that on the amcrest page (https://www.home-assistant.io/integrations/amcrest) that newer firmware cameras could have issues with the video, but this appears to be more related to even logging in. The weird part is that it does actually log in. I see a metric crap-ton of login/logoff events in the log on the camera, and the fact that the HA log shows that it did identify the camera as my front camera. I’ve isolated all logs in at the debug log level related to my camera below as well as results of running the failed commands in my browser (I haven’t had a chance to try to curl from HASS just yet). Anyone got any ideas on why this is failing?

2019-10-02 10:25:33 DEBUG (SyncWorker_3) [amcrest.http] <None:None> Trying Basic Authentication
2019-10-02 10:25:33 DEBUG (SyncWorker_3) [amcrest.http] <None:None> Running query attempt 1
2019-10-02 10:25:36 WARNING (SyncWorker_3) [amcrest.http] <None:None> Trying again due to error: ConnectTimeout(MaxRetryError("HTTPConnectionPool(host='x.x.x.x', port=80): Max retries exceeded with url: /cgi-bin/magicBox.cgi?action=getMachineName (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at ADDRESS>, 'Connection to x.x.x.x timed out. (connect timeout=3.05)'))"))
2019-10-02 10:25:36 DEBUG (SyncWorker_3) [amcrest.http] <None:None> Running query attempt 2
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [amcrest.http] <None:None> Query failed due to error: ConnectTimeout(MaxRetryError("HTTPConnectionPool(host='x.x.x.x', port=80): Max retries exceeded with url: /cgi-bin/magicBox.cgi?action=getMachineName (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at ADDRESS>, 'Connection to x.x.x.x timed out. (connect timeout=3.05)'))"))
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=enable_recording>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=disable_recording>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=camera, service=enable_motion_detection>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=enable_audio>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=camera, service=disable_motion_detection>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=disable_audio>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=camera, service=turn_off>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=enable_motion_recording>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=camera, service=turn_on>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=camera, service=snapshot>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=camera, service=play_stream>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=camera, service=record>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=camera>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event platform_discovered[L]: service=load_platform.camera, platform=amcrest, discovered=name=front>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=disable_motion_recording>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=goto_preset>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=set_color_bw>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=start_tour>
2019-10-02 10:25:39 DEBUG (SyncWorker_3) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=amcrest, service=stop_tour>
2019-10-02 10:25:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=amcrest>
2019-10-02 10:25:39 INFO (MainThread) [homeassistant.components.camera] Setting up camera.amcrest
2019-10-02 10:25:39 DEBUG (SyncWorker_4) [homeassistant.components.amcrest.camera] Updating front camera
2019-10-02 10:25:39 DEBUG (SyncWorker_4) [amcrest.http] <None:None> Running query attempt 1
2019-10-02 10:25:42 WARNING (SyncWorker_4) [amcrest.http] <None:None> Trying again due to error: ConnectTimeout(MaxRetryError("HTTPConnectionPool(host='x.x.x.x', port=80): Max retries exceeded with url: /cgi-bin/magicBox.cgi?action=getVendor (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at ADDRESS>, 'Connection to x.x.x.x timed out. (connect timeout=3.05)'))"))
2019-10-02 10:25:42 DEBUG (SyncWorker_4) [amcrest.http] <None:None> Running query attempt 2
2019-10-02 10:25:45 DEBUG (SyncWorker_4) [amcrest.http] <None:None> Query failed due to error: ConnectTimeout(MaxRetryError("HTTPConnectionPool(host='x.x.x.x', port=80): Max retries exceeded with url: /cgi-bin/magicBox.cgi?action=getVendor (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at ADDRESS>, 'Connection to x.x.x.x timed out. (connect timeout=3.05)'))"))
2019-10-02 10:25:45 DEBUG (SyncWorker_4) [homeassistant.components.amcrest] front camera errs: 1
2019-10-02 10:25:45 ERROR (SyncWorker_4) [homeassistant.components.amcrest.camera] Could not get front camera attributes due to error: CommError
2019-10-02 10:25:45 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=camera.front, old_state=None, new_state=<state camera.front=idle; access_token=REDACTED, friendly_name=front, entity_picture=/api/camera_proxy/camera.front?token=REDACTED, supported_features=3 @ 2019-10-02T10:25:45.730470-04:00>>
2019-10-02 10:26:01 DEBUG (SyncWorker_3) [homeassistant.components.amcrest.camera] Updating front camera
2019-10-02 10:26:01 DEBUG (SyncWorker_3) [amcrest.http] <None:None> Running query attempt 1
2019-10-02 10:26:04 WARNING (SyncWorker_3) [amcrest.http] <None:None> Trying again due to error: ConnectTimeout(MaxRetryError("HTTPConnectionPool(host='x.x.x.x', port=80): Max retries exceeded with url: /cgi-bin/magicBox.cgi?action=getVendor (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at ADDRESS>, 'Connection to x.x.x.x timed out. (connect timeout=3.05)'))"))
2019-10-02 10:26:04 DEBUG (SyncWorker_3) [amcrest.http] <None:None> Running query attempt 2
2019-10-02 10:26:07 DEBUG (SyncWorker_3) [amcrest.http] <None:None> Query failed due to error: ConnectTimeout(MaxRetryError("HTTPConnectionPool(host='x.x.x.x', port=80): Max retries exceeded with url: /cgi-bin/magicBox.cgi?action=getVendor (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at ADDRESS>, 'Connection to x.x.x.x timed out. (connect timeout=3.05)'))"))
2019-10-02 10:26:07 DEBUG (SyncWorker_3) [homeassistant.components.amcrest] front camera errs: 2
2019-10-02 10:26:07 ERROR (SyncWorker_3) [homeassistant.components.amcrest.camera] Could not get front camera attributes due to error: CommError

Browser queries:
http://x.x.x.x/cgi-bin/magicBox.cgi?action=getMachineName
name=AMCRESTSERIALNUMBERHERE

http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor
vendor=Amcrest

The amcrest.http output indicates that the camera is not responding. Did you try those browser queries from the same machine/context that is running HA? Are you sure you have the IP address & port configured correctly in HA?

Yup, IP and port are fine, I literally copy/pasted the line out when it had the IP in there and it worked fine. You bring up a good point though, even though I said I saw it logging in “a metric crap-ton” apparently I was looking at yesterday when I was playing around with the camera. I just re-looked at the amcrest log and it does NOT in fact show HASS logging in, so at least I know I’m not going insane now. :relieved: I can’t test from HASS right now as I’m not home and don’t have my ssh key handy. I am able to test from my VPN’d connection via browser though and see the results I posted at the bottom of my first post. I guess any forward movement on this might have to wait until then.

I’m pretty sure it’s a networking issue between HA and the camera. You’ll need to at least attempt to ping it from the same machine that HA is running on (or, as you mentioned, use curl.) Interesting, though, that some cameras work but this one doesn’t. Everything on the same subnet?

That’s the fun part. I’ve got an IoT subnet that I use for things like my cameras and I tightly control what can get in/out of the subnet (spoiler alert, no internet). The ironic part is that HA and that particular camera are running on my main subnet (literally 1 ip away from each other) because I want my front camera to hit the amcrest cloud as an off-site backup (just in case). Also, my IoT subnet is over WLAN only, and since this is a PoE camera, I have to re-architect everything to get it to work over there.

Also, does this indicate a partial connection since it’s getting a token, etc?

2019-10-02 10:25:45 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=camera.front, old_state=None, new_state=<state camera.front=idle; access_token=REDACTED, friendly_name=front, entity_picture=/api/camera_proxy/camera.front?token=REDACTED, supported_features=3 @ 2019-10-02T10:25:45.730470-04:00>>

No, that token has nothing to do with the low-level communications between the amcrest package and the camera. That’s some sort of id used by the HA camera component-level code.

You’ll note in the previous log you shared the message “Trying Basic Authentication.” This is where it tries to log into the camera using Basic Authentication. Normally that will result in a login error (since recent Amcrest camera versions use Digest Authentication) and it will try again using Digest Authentication, which you’d see in the log, and which would normally work. That is where the authorization data comes from that will be used until HA restarts (or it fails, e.g., if you change the password in the camera.)

BTW, I’m assuming the state of camera.front eventually changes to unavailable.

Ah, gottcha. I just ran debugger in chrome and saw that it is indeed using digest authentication. I also checked back in the HASS log and it looks like it’s only trying to use basic authentication. I don’t see any mention of attempting digest authentication. I’ll try to poke around at the amcrest component and see if I can’t figure out why it’s not attempting digest (assuming the code for it is there) and we’ll see about contributing to HASS that way :slight_smile:

I can tell you exactly why it’s not trying Digest Authentication. (I wrote the code. :slight_smile:) It’s because it’s not getting a login error (specifically ERROR 401) because the camera isn’t responding at all. Hence the ConnectTimeout.

WOW! Now that’s what I call service! :crazy_face:
I didn’t get a chance to do anything yesterday (kids, what can I say), but I did just throw some curl at it and these were my results:

core-ssh:~# #using basic auth and good creds
core-ssh:~# curl --basic --user admin http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor
Enter host password for user 'admin':
core-ssh:~# #no results displayed
core-ssh:~#
core-ssh:~#
core-ssh:~# #trying basic auth and bad creds, just in case
core-ssh:~# curl --basic --user admin http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor
Enter host password for user 'admin':
core-ssh:~# #looks about right so far
core-ssh:~#
core-ssh:~#
core-ssh:~# #trying with digest auth and good creds
core-ssh:~# curl --digest --user admin http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor
Enter host password for user 'admin':
vendor=Amcrest
core-ssh:~# #nothing unexpected
core-ssh:~#
core-ssh:~#
core-ssh:~# #trying digest auth and bad creds just to see result
core-ssh:~# curl --digest --user admin http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor
Enter host password for user 'admin':
Error
Invalid Authority!
core-ssh:~# #makes sense
core-ssh:~#
core-ssh:~#
core-ssh:~# #trying with good creds, but bad action
core-ssh:~# curl --digest --user admin http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendo
Enter host password for user 'admin':
Error
Bad Request!
core-ssh:~#
core-ssh:~# #huh...

I’m going to get some pcap while I’m at it to really see what’s going on rather that just relying on the output of curl, I’ll check back in a few.

You can also use curl’s -v option to see more details about what’s going on.

All your output seems reasonable & expected.

But are you running curl in the same exact context that HA runs in? Same user? Same container? …?

Yeah, while I was getting tcpdump installed, I noticed that was on a totally different subnet and immediately suspected I’d been docker’d. Is this where I should even be testing connectivity from? I’m not very wise to the ways of docker. All I know is I’ve ssh’d in via the ssh plugin for HASS. Not sure if at this point I need to be on my hassio’s vm console to go interactive on [fill in random container here] or if where I’m already at is where the amcrest component resides (I suspect not based on my find results).

Sorry, can’t help you. I don’t use hassio, docker, … Just a simple Ubuntu OS and HA installed into a venv.

Sounds like a dream to manage… I’ll poke around at it and see what I can find. In the meantime, thanks a ton for pointing me in the right direction! :smiley:

1 Like

w00t! shell_command FTW!
Here’s my output (I cleaned it up a bit for readability).

The good stuff is in the STDERR. That explains why I was getting a result, but it was still failing.

2019-10-03 18:06:13 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.140550098879824] Received {'type': 'call_service', 'domain': 'shell_command', 'service': 'basic_curl', 'service_data': {}, 'id': 22}
2019-10-03 18:06:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=shell_command, service=basic_curl, service_data=>
2019-10-03 18:06:13 DEBUG (MainThread) [homeassistant.components.shell_command] Stderr of command: `curl -v --basic --user test:testTEST http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor`, return code: 0:
b'
*   Trying x.x.x.x:80...
* TCP_NODELAY set
* Connected to x.x.x.x (x.x.x.x) port 80 (#0)
* Server auth using Basic with user \'test\'
> GET /cgi-bin/magicBox.cgi?action=getVendor HTTP/1.1
> Host: x.x.x.x
> Authorization: Basic BASE64_HORRIBLE_PASSWORD_IDEA_IETF
> User-Agent: curl/7.65.1
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 401 Unauthorized
< WWW-Authenticate: Digest realm="Login to REDACTED", qop="auth", nonce="NONCE", opaque="OPAQUE"
< Connection: close
< CONTENT-LENGTH: 0
< 
* Closing connection 0
'



2019-10-03 18:06:13 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.140550098879824] Sending {'id': 22, 'type': 'result', 'success': True, 'result': None}
2019-10-03 18:06:26 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.140550098879824] Received {'type': 'call_service', 'domain': 'shell_command', 'service': 'digest_curl', 'service_data': {}, 'id': 23}
2019-10-03 18:06:26 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=shell_command, service=digest_curl, service_data=>
2019-10-03 18:06:26 DEBUG (MainThread) [homeassistant.components.shell_command] Stdout of command: `curl -v --digest --user test:testTEST http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor`, return code: 0:
b'
vendor=Amcrest
'
2019-10-03 18:06:26 DEBUG (MainThread) [homeassistant.components.shell_command] Stderr of command: `curl -v --digest --user test:testTEST http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor`, return code: 0:
b'
*   Trying x.x.x.x:80...
* TCP_NODELAY set
* Connected to x.x.x.x (x.x.x.x) port 80 (#0)
* Server auth using Digest with user \'test\'
> GET /cgi-bin/magicBox.cgi?action=getVendor HTTP/1.1
> Host: x.x.x.x
> User-Agent: curl/7.65.1
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 401 Unauthorized
< WWW-Authenticate: Digest realm="Login to REDACTED", qop="auth", nonce="NONCE", opaque="OPAQUE"
< Connection: close
< CONTENT-LENGTH: 0
< 
* Closing connection 0
* Issue another request to this URL: \'http://x.x.x.x/cgi-bin/magicBox.cgi?action=getVendor\'
* Hostname x.x.x.x was found in DNS cache
*   Trying x.x.x.x:80...
* TCP_NODELAY set
* Connected to x.x.x.x (x.x.x.x) port 80 (#1)
* Server auth using Digest with user \'test\'
> GET /cgi-bin/magicBox.cgi?action=getVendor HTTP/1.1
> Host: x.x.x.x
> Authorization: Digest username="test", realm="Login to REDACTED", nonce="NONCE", uri="/cgi-bin/magicBox.cgi?action=getVendor", cnonce="CNONCE=", nc=00000001, qop=auth, response="REPONSE", opaque="OPAQUE"
> User-Agent: curl/7.65.1
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Content-type: text/plain;charset=utf-8
< CONNECTION: close
< CONTENT-LENGTH: 16
< 
{ [16 bytes data]
* Closing connection 1
'
2019-10-03 18:06:26 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection.140550098879824] Sending {'id': 23, 'type': 'result', 'success': True, 'result': None}

I guess I’m a bit confused. This suggests that the amcrest component should have worked, yet it didn’t.

The amcrest component will first attempt using basic authentication (to support older models.) If that fails with an error 401 (Unauthorized) it will then attempt using digest authentication.

This is what the output from the curl commands show. I.e., basic fails with error 401, but digest works.

BUT, when the amcrest component tried basic authentication, it didn’t fail with an error 401, it failed with a ConnectTimeout. I.e., the camera did not return error 401, it in fact returned nothing.

I suspect the shell_command is still not running in the right container/context. I’m probably going to have to stop cheating and just get into the docker itself :unamused:

Well, FWIW, it uses asyncio.subprocess.create_subprocess_shell or asyncio.subprocess.create_subprocess_exec. I can’t say I really know how those work, but I’d assume they run at least in the same docker as HA.

And now you know why I don’t bother with hassio, docker, etc. :wink: Yes, I guess I miss out on “add ons”, and probably other advantages, but in a year and a half using HA, I’ve not missed them.

1 Like

I am in the same boat;

Getting a lot of error messages in HA logs, but I do get stream and snapshot of the amcrest camera in HA (so it is working but spoiling the error logs).

2020-08-06 11:17:00 DEBUG (SyncWorker_6) [homeassistant.components.amcrest] els_wash_210 camera errs: 1
2020-08-06 11:17:00 ERROR (SyncWorker_6) [homeassistant.components.amcrest.camera] Could not get els_wash_210 camera attributes due to error: CommError
2020-08-06 11:17:00 DEBUG (SyncWorker_7) [homeassistant.components.amcrest.camera] Updating els_beik_215 camera
2020-08-06 11:17:00 WARNING (SyncWorker_7) [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')

I am also on hassio.

my configuration.yaml

amcrest:
  - host: 192.168.2.200
    name: els_flur_200
    username: !secret cctv_user
    password: !secret cctv_password
  #  authentication: digest
    resolution: low
    sensors:
 #     - motion_detector
  #    - sdcard
  #  switches:
  #    - motion_detection
   #   - motion_recording

Tried curl -v on a terminal console of my HA host (terminal within HA):

 -» ~ curl --digest --user admin http://192.168.2.200/cgi-bin/magicBox.cgi\?action\=getVendor -v Enter host password for user 'admin':
* Trying 192.168.2.200:80...
* TCP_NODELAY set
* Connected to 192.168.2.200 (192.168.2.200) port 80 (#0)
* Server auth using Digest with user 'admin'
> GET /cgi-bin/magicBox.cgi?action=getVendor HTTP/1.1
> Host: 192.168.2.200
> User-Agent: curl/7.67.0
> Accept: */* >
* Mark bundle as not supporting multiuse
< HTTP/1.1 401 Unauthorized
< WWW-Authenticate: Digest realm="Login to 2J0225PZA8H0318", qop="auth"J nonce="279112332", Opaque="480b6bc94748118c5fa5077c9071664900fbfd50"
< Connection: close
< Set-Cookie:secure; HttpOnly
< CONTENT-LENGTH: 0
<
* Closing connection 0
* Issue another request to this URL: ,http://192.168.2.200/cgi-bin/magicBox.cgi?action=getVendor'
* Hostname 192.168.2.200 was found in DNS cache
*
Trying 192.168.2.200:80...
* TCP_NODELAY set
* Connected to 192.168.2.200 (192.168.2.200) port 80 (#1)
* Server auth using Digest with user 'admin'
> GET /cgi-bin/magicBox.cgi?action=getVendor HTTP/1.1
> Host: 192.168.2.200
> Authorization: Digest username="admin", realm="Login to 2J0225PZA8H0318", nonce="279112332", uri="/cgi-bin/magicBox.cgi?action=getVendor"J cnonce="MzBiMmU4OTY4Mzg2YzJkN2VhYTRkYzYlZjA0NmYlZTc=" , nc=00000001, qop=auth, response="e940054334e668f25f9d28c9c07e003f", Opaque="480b6bc94748118c5fa5077c9071664900fbfd50"
> User-Agent: curl/7.67.0
> Accept: */* >
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Content-type: text/plain;charset=utf-8
< CONNECTION: close
< Set-Cookie:secure; HttpOnly
< CONTENT-LENGTH: 14
<
vendor=Dahua
* Closing connection 1

any idea?

What version of HA are you using?