jahkeup / prometheus-moto-exporter

Motorola Modem Prometheus Exporter (mb8600)
GNU Lesser General Public License v2.1
18 stars 12 forks source link

Works exactly 1 time with MB8611 #32

Open johlym opened 1 year ago

johlym commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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: CleanShot 2023-01-10 at 22 14 10

hollec commented 1 year ago

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 commented 1 year ago

Same result as before on this end: CleanShot 2023-01-11 at 16 59 06

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

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 https://github.com/jahkeup/prometheus-moto-exporter/issues/32#issuecomment-1849296570, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAE44SWOWFWL2RKBWUH22KTYI2B6NAVCNFSM6AAAAAATUXHFOWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQNBZGI4TMNJXGA . You are receiving this because you were mentioned.Message ID: @.***>