Intermittent unknown server errors

[pdelagrave]

redacted.logs.zip Hi

We are using the LastPass CLI v1.1.2 on linux in an automated script that is part of an automated testing framework. We create websites and generate their credentials as a part of that testing framework and we use LastPass to to store the credentials and make them easily accessible to our developers.

We get the error message Error: HTTP response code said error. at random times. The exact same lpass commands will work many times in a row but sometime will fail with that error message. The redacted debug logs are attached and are showing a 403 Forbidden error is returned by the server. We know the account used have access so that's an unexpected error message.

It seems the body of errored HTTP responses are helpful when testing requests with curl, but they aren't included in the debug logs. Including them would help a lot.

Thanks

Pierre Delagrave

[bcopeland]

You are probably hitting the rate limiting.

Good news, you can get all the curl debug output by setting LPASS_LOG_LEVEL=8 (or by using an MITM proxy).

[pdelagrave]

What are the exact parameters for the rate limiting?

We are already using LPASS_LOG_LEVEL=8 but the body isn't printed in the logs.

[thadeshammer]

@pdelagrave if it helps, I've managed to automate handling of the rate limiting to a large extent using automatic retries with simple exponential back-off. Most of the time now I just need to wait for scripts to finish rather than manually re-initiating them.

[pdelagrave]

@thadeshammer Thanks for the suggestion! We already handle the error with retry code but that's very awkward when you initially only had a simple bash script, and still fails sometimes. We are not hammering the service at all and are using a corporate account so I'd expect something like that to be solvable.

[thadeshammer]

@pdelagrave NP! Yep, I felt the same way at first...but I think part of the issue is that the rate limiting maybe isn't targeted at users, but just ramps up based on their overall traffic. Just a hypothesis, but I've noticed that the interruptions seem more likely and more frequent as the day goes on (light in the morning, moderate at lunch, heavy in the afternoon). I'd be curious for @bcopeland to confirm or deny if he can?

[pdelagrave]

@bcopeland Hi Bob Is it possible to know how the rate limiting is configured on the server and if an individual client has an input to triggering it?

Thanks

[bcopeland]

@pdelagrave I don't believe I can disclose the actual limits because reasons, however, I will note that one common cause is if you have a large company behind a single IP, you can hit them more readily because a lot of limits are IP-based. If that is the case, you can ask your customer care representative to raise the thresholds.

[pdelagrave]

@bcopeland Wouldn't publishing the rate limiting details actually encourage the customers to responsively query the service?

https://dev.twitter.com/rest/public/rate-limiting https://developers.facebook.com/docs/graph-api/advanced/rate-limiting https://help.shopify.com/api/getting-started/api-call-limit https://developer.github.com/v3/#rate-limiting

That being said, the issue is that we don't even know why we get the error in the first place. Asking about rate limiting was a way to verify if that could be the reason. After 9 messages in this thread we're still at the same stage.

Would adding the body of the HTTP request and response with make sense as a feature request? LPASS_LOG_LEVEL=9 ? I could then provide that log back to you when we experience the failure. Given that the server returns some information upon an error, which seem to be the case when playing around with curl and the lpass backend endpoints.

[thadeshammer]

@pdelagrave it's an undocumented "feature." LPASS_LOG_LEVEL is an environment variable that lpass-cli looks for. You can see this in log.h and log.c, where you may also notice that the max logging level in the comments is 8.

I did try 9 anyway (on faith) and it did barf a lot of (useless at the time) stuff for me. It's much more about debugging the CLI application than it is about providing useful feedback to end-users, I think.

[bcopeland]

@pdelagrave sure, I'll take a patch adding more stuff to loglevel 8. Right now it includes CURLOPT_VERBOSE logging from libcurl -- which does include bodies at least for successful requests.

[Codelica]

Running into "Error: HTTP response code said error." also.

We use lpass in a bash/expect script to backup our enterprise account data. It's on a CentOS 6 machine and runs daily in the middle of the night. It started exiting at our initial lpass "ls" command (with that error) out of the blue about a week ago. Thought it might be a temporary service issue, but it's persisted.

Then thinking it was some API change, I updated our lpass command with a build of the latest. Same output. Login is fine, lpass ls results in the error.

Decided to try install/build lpass on a newer Ubuntu 16.04 server, but got the same results.

Perhaps something else is at work with the API now? Any ideas would be appreciated. Perhaps there is a better way to do complete account backup at this point.

Thanks..

[Codelica]

Still at a loss on this one. We aren't using the API excessively, like literally a handful of calls one a day in the middle of the night. And it started out of the blue. We can lpass login fine, but followed by and lpass ls we get what appears to be a 403:

<7> [1510612111.034415] Making request to https://lastpass.com/getaccts.php
* About to connect() to lastpass.com port 443 (#0)
*   Trying 184.85.81.170... * connected
* Connected to lastpass.com (184.85.81.170) port 443 (#0)
* Initializing NSS with certpath: sql:/etc/pki/nssdb
*   CAfile: /etc/pki/tls/certs/ca-bundle.crt
  CApath: none
* SSL connection using TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
* Server certificate:
*   subject: CN=lastpass.com,O="LogMeIn, Inc",OU=LastPass,STREET=320 Summer St Ste 100,L=Boston,ST=Massachusetts,C=US,incorporationState=Massachusetts,incorporationCountry=US,serialNumber=000873622,businessCategory=Private Organization
*   start date: Jun 13 16:58:09 2016 GMT
*   expire date: Jun 14 16:58:09 2018 GMT
*   common name: lastpass.com
*   issuer: CN=GlobalSign Extended Validation CA - SHA256 - G2,O=GlobalSign nv-sa,C=BE
> POST /getaccts.php HTTP/1.1
User-Agent: LastPass-CLI/1.2.2
Host: lastpass.com
Accept: */*
Cookie: PHPSESSID=[SOMETHING-I-EDITED-OUT]
Content-Length: 39
Content-Type: application/x-www-form-urlencoded

* The requested URL returned error: 403 Forbidden
* Closing connection #0
* HTTP response code said error

Anything else I can do to troubleshoot? Unless we have a good backup route, I don't see this lasting long. :/

[thadeshammer]

Hey @Codelica ,

Is your ~/.lpass/upload-queue (I think that's the name of the folder) empty? Sometimes cruft builds up in there that I've seen cause ls queries to either fail (403) or just hang forever. Back that directory's contents up somewhere (honestly, I've always just deleted it, but juuuust incase) then try again.

I should note that I'm using an older version of the CLI and people with the newer version are having trouble (and thus rolling back to 1.1 with me) but if you're just running ls and getting a 403 I don't think the API change is to blame there.

[Codelica]

Interesting, thanks for the info!

Since we were using a very old version (v0.4.0 which worked fine until recently), I downloaded and tried v1.2.2. I did completely clear ~/.lpass completely as part of my testing. Looking in there now, I don't see anything with "upload" or "queue" in the name. But you do have me curious about v1.1. I'll give that a shot...

Edit: Just tried v1.1.0, got the same results..

[bcopeland]

If you are getting 403 it's most likely that you are hitting per-ip rate limits. When lastpass-cli sees that, it should start backing off (taking a lot longer to complete in some cases).

On Tue, Nov 14, 2017 at 12:57:11AM +0000, James wrote:

Interesting, thanks for the info!

Since we were using a very old version (v0.4.0 which worked fine until recently), I downloaded and tried v1.2.2. I did completely clear ~/.lpass completely as part of my testing. Looking in there now, I don't see anything with "upload" or "queue" in the name. But you do have me curious about v1.1. I'll give that a shot...

-- You are receiving this because you were mentioned. Reply to this email directly or view it on GitHub: https://github.com/lastpass/lastpass-cli/issues/304#issuecomment-344110094

[thadeshammer]

Thanks for weighing in, @bcopeland !

Any chance the feedback the CLI gives around this kind of thing could be improved upon? A "You're being rate limited" vs "403" would be pretty nice.

Also, could you please share with us what the rate limits are?

[Codelica]

Well, at least in our case, I can't see how it would be rate limiting. It literally only gets run once a day (late at night), and it's failing on the 2nd call -- right after login (which always "works"). Unless the rate limiting possibly groups clients by some netmask I guess. This is on a private VM at Linode.

[pdelagrave]

@Codelica After the experience from this thread and in private exchanges with support, I think LastPass made it clear that they don't consider fixing, explaining or understanding these problems, even for corporate customers.

The solution for us was to stop using LP and migrate to different credentials management system.

[bcopeland]

@Codelica can you tell me your IP? Then I can check server logs. (Email at the one in the git commit log is OK).

[awick]

Just started having this same problem with 1.2.2. I've tried from multiple source ips. Tried deleting my .lpass directory. Chrome plugin works fine. Nothing really interesting in lpass.log

Host: lastpass.com^M
User-Agent: LastPass-CLI/1.2.2^M
Accept: */*^M
Cookie: PHPSESSID=<REMOVED>^M
Content-Length: 39^M
Content-Type: application/x-www-form-urlencoded^M
^M
* upload completely sent off: 39 out of 39 bytes
* The requested URL returned error: 403 Forbidden```

[bcopeland]

I forgot to leave a follow-up here: in @Codelica 's case the problem was that the account in question had fallen afoul of the password expiration policy set for his enterprise. When that happens, getaccts.php will return a 403 even though login check will succeed (but a full logout / login should also show the real reason for denial).

[awick]

Yep that was it. lpass logout/login didn't warn me, once I did a chrome logout/login did I get the error. Thanks!

[bcopeland]

OK, I'll have a look into doing better error reporting here for lpass.