Works exactly 1 time with MB8611

[johlym]

Found this and thought it'd be useful to put against my MB8611. What I'm seeing is that the first collection works fine, but subsequent collections fail until "no response" is given. That correlates with a lockout from invalid login attempts, so working back further, the EOFs are invalid logins.

~# /usr/local/bin/prometheus-moto-exporter --endpoint https://192.168.100.1 --username ***** --password ***** --debug
DEBU[0000] configured for HNAP metrics                   endpoint="https://192.168.100.1" username=*****
INFO[0000] starting server on 127.0.0.1:9731             context=server
INFO[0000] collecting                                    context=collect
DEBU[0000] requesting challenge                          action=login
DEBU[0000] accepting challenge                           action=login
DEBU[0000] submitting response                           action=login
DEBU[0000] response sent                                 action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
INFO[0008] finished collecting                           context=collect
INFO[0008] completed successfully                        context=collect
INFO[0030] collecting                                    context=collect
DEBU[0030] requesting challenge                          action=login
DEBU[0030] accepting challenge                           action=login
DEBU[0030] submitting response                           action=login
DEBU[0030] response sent                                 action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
INFO[0030] finished collecting                           context=collect
ERRO[0030] collection error                              context=collect error=EOF
INFO[0060] collecting                                    context=collect
DEBU[0060] requesting challenge                          action=login
DEBU[0060] accepting challenge                           action=login
DEBU[0060] submitting response                           action=login
DEBU[0060] response sent                                 action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
INFO[0060] finished collecting                           context=collect
ERRO[0060] collection error                              context=collect error=EOF
INFO[0090] collecting                                    context=collect
DEBU[0090] requesting challenge                          action=login
DEBU[0090] accepting challenge                           action=login
DEBU[0090] submitting response                           action=login
DEBU[0090] response sent                                 action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
INFO[0090] finished collecting                           context=collect
ERRO[0090] collection error                              context=collect error=EOF
INFO[0120] collecting                                    context=collect
DEBU[0120] requesting challenge                          action=login
DEBU[0120] accepting challenge                           action=login
DEBU[0120] submitting response                           action=login
DEBU[0120] response sent                                 action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
INFO[0120] finished collecting                           context=collect
ERRO[0120] collection error                              context=collect error="cannot fetch data: no response found "
^CINFO[0123] SIGINT: shutting down server
INFO[0123] shutting down server                          context=server
INFO[0123] server shutdown                               context=server
INFO[0123] done

I'm not well-versed enough in Golang to be able to answer this myself adequately, but I was able to produce a case where this stops being an issue: killing and restarting the exporter after the first metrics gather:

~# /usr/local/bin/prometheus-moto-exporter --endpoint https://192.168.100.1 --username ***** --password ***** --debug
DEBU[0000] configured for HNAP metrics                   endpoint="https://192.168.100.1" username=*****
INFO[0000] starting server on 127.0.0.1:9731             context=server
INFO[0000] collecting                                    context=collect
DEBU[0000] requesting challenge                          action=login
DEBU[0000] accepting challenge                           action=login
DEBU[0000] submitting response                           action=login
DEBU[0000] response sent                                 action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
INFO[0008] finished collecting                           context=collect
INFO[0008] completed successfully                        context=collect
^CINFO[0010] SIGINT: shutting down server
INFO[0010] shutting down server                          context=server
INFO[0010] server shutdown                               context=server
INFO[0010] done
~# /usr/local/bin/prometheus-moto-exporter --endpoint https://192.168.100.1 --username ***** --password ***** --debug
DEBU[0000] configured for HNAP metrics                   endpoint="https://192.168.100.1" username=*****
INFO[0000] starting server on 127.0.0.1:9731             context=server
INFO[0000] collecting                                    context=collect
DEBU[0000] requesting challenge                          action=login
DEBU[0000] accepting challenge                           action=login
DEBU[0000] submitting response                           action=login
DEBU[0000] response sent                                 action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
INFO[0009] finished collecting                           context=collect
INFO[0009] completed successfully                        context=collect
^CINFO[0009] SIGINT: shutting down server
INFO[0009] shutting down server                          context=server
INFO[0009] server shutdown                               context=server
INFO[0009] done
~# /usr/local/bin/prometheus-moto-exporter --endpoint https://192.168.100.1 --username ***** --password ***** --debug
DEBU[0000] configured for HNAP metrics                   endpoint="https://192.168.100.1" username=*****
INFO[0000] starting server on 127.0.0.1:9731             context=server
INFO[0000] collecting                                    context=collect
DEBU[0000] requesting challenge                          action=login
DEBU[0000] accepting challenge                           action=login
DEBU[0000] submitting response                           action=login
DEBU[0000] response sent                                 action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
INFO[0008] finished collecting                           context=collect
INFO[0008] completed successfully                        context=collect
^CINFO[0009] SIGINT: shutting down server
INFO[0009] shutting down server                          context=server
INFO[0009] server shutdown                               context=server
INFO[0009] done

Thoughts?

[hollec]

Interesting. This works with my MB8611, but I am using it via Docker. The software version on my modem is 8611-19.2.18.

Separately, the regular web interface will prevent logins, but this continues working in the background for days or weeks.

[johlym]

Hmm. I’m on 8611-21.3.7. I wonder if they changed something. On Jan 10, 2023, at 2:45 PM, Chris Hollenbeck ***@***.***> wrote: Interesting. This works with my MB8611, but I am using it via Docker. The software version on my modem is 8611-19.2.18. —Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you authored the thread.Message ID: ***@***.***>

[johlym]

So far as I can tell, HNAP_AUTH is only good for a single request. This would explain why it works once but not a second time. Is Login supposed to run every collection? if it is, it's not in my case, thus the expired HNAP_AUTH and eventual lockout.

@hollec what version of Golang are you running? I'm using 1.19.4 on Ubuntu 22.04. Happy to try to reproduce with your version if it's different.

Edited to add: Tried within Docker, same result:

[hollec]

I'm on a slightly older docker version via docker-compose and an .env file for authentication variables.

version: "3.7"
services:
  prometheus-moto-exporter:
    container_name: prometheus-moto-exporter
    image: ghcr.io/jahkeup/prometheus-moto-exporter:v1.0.0-rc2
    restart: unless-stopped
    ports:
      - '9731:9731'
    environment:
      - MOTO_USERNAME
      - MOTO_PASSWORD

Adjusted .env file:

MOTO_USERNAME=username
MOTO_PASSWORD=password

Container log snippet:

time="2023-01-11T22:49:24Z" level=info msg=collecting context=collect
time="2023-01-11T22:49:30Z" level=info msg="finished collecting" context=collect
time="2023-01-11T22:49:30Z" level=info msg="completed successfully" context=collect
time="2023-01-11T22:49:54Z" level=info msg=collecting context=collect
time="2023-01-11T22:50:00Z" level=info msg="finished collecting" context=collect
time="2023-01-11T22:50:00Z" level=info msg="completed successfully" context=collect

[johlym]

Same result as before on this end:

I wonder if the firmware version changed something about authentication... 🤔 I alluded to this earlier, but HNAP_AUTH seems to rotate now. Did it use to? (Does it with your version? I spotted it in my browser console after logging in; one of the background POST requests to the /HNAP1 endpoint)

The fact that it works on the first collect but not subsequent collects really seems to indicate the auth token is practically one-time use with current firmware. I also suspect that if you're ever unfortunately blessed with this newer firmware, the same effect will make its way to you.

[johlym]

I wanted to pass along a heads-up that I've been rolled back to 8611-19.2.18 and the exporter works as it should. Keep an eye out for a future update to the newer version, again, because it'll certainly break this exporter.

[jahkeup]

Found this and thought it'd be useful to put against my MB8611.

Sweet! I'd hoped that this would work against some other models, let's see what we can do to get the exporter working consistently.

What I'm seeing is that the first collection works fine, but subsequent collections fail until "no response" is given.

If you were to run again later (after any lockout times out), does collection succeed only on the first attempt, followed by the failures? Or, after the first success case will all subsequent runs fail until your modem is reset?

---

Separately, the regular web interface will prevent logins, but this continues working in the background for days or weeks.

You know, I saw something like during my initial testing when I would move between a reset/clean-state to configured by boot file from my ISP: some functionality would progressively lock down and become inaccessible. In my case, they were disabling SNMP access (which the MB8600 has but is blocked.. and is why I wrote this exporter!). So, I'd be suspicious of impending ISP policy changes that could be impacting login :(

[johlym]

Thanks for following up @jahkeup and 👋🏻 fellow PNWer.

If you were to run again later (after any lockout times out), does collection succeed only on the first attempt, followed by the failures? Or, after the first success case will all subsequent runs fail until your modem is reset?

Under the newer 8611-21.3.7 firmware... I think I can best answer this question by saying that if I ran the exporter long enough for it to export exactly one time, killed it, immediately restarted it, and repeated this pattern indefinitely, it'd work fine. The modem doesn't seem to need any period of time between run-kill-run. (as if the token that's generated is good exactly one time)

I was downgraded back to the 8611-19.2.18 firmware and things work fine as they are, today; no changes are required.

[guusbosman]

I'm experiencing the same thing on my MB 8600. The firmware version is 8600-21.3.3, and I'm using prometheus-moto-exporter from Docker on a Raspberry Pi.

For what it's worth, earlier I was using https://github.com/uoodsq/moto (on a different machine, not in Docker), and that ran fine in continuous mode.

pi-moto_exporter-1  | time="2023-12-07T00:01:44Z" level=debug msg="configured for HNAP metrics" endpoint="https://192.168.100.1/HNAP1/" username=admin
pi-moto_exporter-1  | time="2023-12-07T00:01:44Z" level=info msg="starting server on 0.0.0.0:9731" context=server
pi-moto_exporter-1  | time="2023-12-07T00:01:44Z" level=info msg=collecting context=collect
pi-moto_exporter-1  | time="2023-12-07T00:01:44Z" level=debug msg="requesting challenge" action=login
pi-moto_exporter-1  | time="2023-12-07T00:01:44Z" level=debug msg="accepting challenge" action=login
pi-moto_exporter-1  | time="2023-12-07T00:01:44Z" level=debug msg="submitting response" action=login
pi-moto_exporter-1  | time="2023-12-07T00:01:44Z" level=debug msg="response sent" action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
pi-moto_exporter-1  | time="2023-12-07T00:02:02Z" level=info msg="finished collecting" context=collect
pi-moto_exporter-1  | time="2023-12-07T00:02:02Z" level=info msg="completed successfully" context=collect
pi-moto_exporter-1  | time="2023-12-07T00:02:14Z" level=info msg=collecting context=collect
pi-moto_exporter-1  | time="2023-12-07T00:02:14Z" level=debug msg="requesting challenge" action=login
pi-moto_exporter-1  | time="2023-12-07T00:02:14Z" level=debug msg="accepting challenge" action=login
pi-moto_exporter-1  | time="2023-12-07T00:02:14Z" level=debug msg="submitting response" action=login
pi-moto_exporter-1  | time="2023-12-07T00:02:14Z" level=debug msg="response sent" action="http://purenetworks.com/HNAP1/Login" action.call=login status=200
pi-moto_exporter-1  | time="2023-12-07T00:02:14Z" level=info msg="finished collecting" context=collect
pi-moto_exporter-1  | time="2023-12-07T00:02:14Z" level=error msg="collection error" context=collect error=EOF
^Ccanceled

[jahkeup]

Hi @guusbosman - thanks for the added case and logs

We'll probably need to get at the underlying HTTP requests and responses, and am wondering what's in the affected login and following collection requests+responses. Let me take a closer look this weekend and I'll come back with some diagnostics useful to address this.

[jahkeup]

I'm seeing some oddities with Login response handling - in that there's not enough/any - that can present this issue. Now adding some trace logs to capture the underlying request and responses to help distinguish the case :)

[guusbosman]

I'm happy to give it a try with the codebase with added logging, if you could point me in the right direction of where to find the right branch.

…

On Sun, Dec 10, 2023, 11:13 PM Jacob Vallejo ***@***.***> wrote: I'm seeing some oddities with Login response handling - in that there's not enough/any - that can present this issue. Now adding some trace logs to capture the underlying request and responses to help distinguish the case :) — Reply to this email directly, view it on GitHub <#32 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAE44SWOWFWL2RKBWUH22KTYI2B6NAVCNFSM6AAAAAATUXHFOWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQNBZGI4TMNJXGA> . You are receiving this because you were mentioned.Message ID: ***@***.***>