e-mission / e-mission-docs

Repository for docs and issues. If you need help, please file an issue here. Public conversations are better for open source projects than private email.
https://e-mission.readthedocs.io/en/latest
BSD 3-Clause "New" or "Revised" License
15 stars 34 forks source link

"Create Label Error" when adding custom label on staging #1080

Open JGreenlee opened 4 months ago

JGreenlee commented 4 months ago

This error occurs when adding any custom label.

It is 100% reproducible using e-mission-phone (at master) and connecting to the staging server. However, it is not reproducible when connecting to a local instance of e-mission-server (also at master); even with e-mission-phone still at master and same config (I was using stage-study). I am perplexed by this.

The error message would suggest malformed JSON, but I inspected what the UI is sending and it looks fine: DEBUG:About to update custom label: {"key":"mode","old_label":"","new_label":"skateboard","is_new_label_must_added":true}

Googling the error message reveals that the error occurs in iOS native code. However, I couldn't find any more details in the loggerDB logs.


On the server logs, it appears that the /customlabel/update request is initiated and immediately exits:

2024-07-25T03:33:57.480Z | 2024-07-25 03:33:57,479:DEBUG:140584710653504:START POST /customlabel/update
-- | --
2024-07-25T03:33:57.480Z | 2024-07-25 03:33:57,480:DEBUG:140584710653504:END POST /customlabel/update 0.0003833770751953125

This is what /customlabel/update should be doing:

@post('/customlabel/update')
def updateUserCustomLabel():
  logging.debug("Called updateUserCustomLabel")
  updated_label = request.json['updated_label']
  user_uuid = getUUID(request)
  user = User.fromUUID(user_uuid)
  to_return = user.updateUserCustomLabel(updated_label)
  logging.debug("Successfully updated label label for user %s" % user_uuid)
  return { 'label' : to_return }

...but not even "Called updateUserCustomLabel" gets logged out.

shankari commented 4 months ago

@JGreenlee interesting. given that:

  1. the local server works but stage doesn't
  2. we are seeing the message reach the stage server
  3. but not show up while processing the stage server

I think that the problem is with a server error, probably related to the database. The error that we actually see is likely because we tried to parse the error on the server as JSON and failed. e.g. https://stackoverflow.com/a/63679740

I checked the server logs, and it looks like the errors don't actually show up in the streamed console logs. It might be easiest to print out the string in the native code before converting to JSON.

@JGreenlee LMK if you can do this, or whether I should (not sure if you are using the devapp or re-building)

JGreenlee commented 4 months ago

@JGreenlee LMK if you can do this, or whether I should (not sure if you are using the devapp or re-building)

I think I can do that. I know how to build; I will just have to learn how to log from Objective-C

JGreenlee commented 4 months ago

The native code is expecting a JSON string in the response, and it receives an HTML string instead. It appears to be the HTML of https://www.nrel.gov/transportation/openpath.html

I think this means the server is not recognizing /customlabel/update as a route and it's defaulting to something else.

@shankari Is there an extra step needed to configure new routes?

shankari commented 4 months ago

We may want to leave that log in (catch the exception, log and then rethrow) to help catch such issues in the future.

Yes that is what it means.

Double-checking using curl, I get... ``` $ curl https://openpath-stage.nrel.gov/api/usercache/get Error: 405 Method Not Allowed

Error: 405 Method Not Allowed

Sorry, the requested URL 'https://openpath-stage.nrel.gov/usercache/get' caused an error:

Method not allowed.
``` ``` $ curl https://openpath-stage.nrel.gov/api/usercache/put Error: 405 Method Not Allowed

Error: 405 Method Not Allowed

Sorry, the requested URL 'https://openpath-stage.nrel.gov/usercache/put' caused an error:

Method not allowed.
``` ``` $ curl https://openpath-stage.nrel.gov/api/customlabel/update $ curl https://openpath-stage.nrel.gov/api/customlabel/get $ ```

It certainly looks like the new API endpoints have not been deployed. There should not be an extra step needed to configure the new routes, as we can see from the fact that the server works locally.

Double-checking deployment steps:

So we should have the new code deployed. I'm going to deploy from the image and see if I can verify. It would be good to also print out some kind of version information from the server at startup so we can verify which version is running.

shankari commented 4 months ago

Ok so this is weird. I build the new image on Jul 23 and it was successful.

Screenshot 2024-07-25 at 6 01 51 PM

But I don't see the related image in the registry

Screenshot 2024-07-25 at 6 02 45 PM

Confirmed that the most recent image (the one from jul 18) does not have the changes.

$ docker run -p 8080:8080 -it <image from jul 18> /bin/bash
root@d246f9a5c2cb:/usr/src/app# grep -r customlabel emission/net/
root@d246f9a5c2cb:/usr/src/app#

So what was deployed? Was it actually the new image? @jgu2 can you take a look on whether this is related to your recent stage versus prod channel changes?

shankari commented 4 months ago

Fixed by @jgu2, re-deployed on staging

@JGreenlee @louisg1337 assuming it does, can one of you submit a PR with the code that Jack added (catch the JSON format exception and rethrow with the raw response)? It will help debug such issues more easily in the future.

JGreenlee commented 4 months ago

https://github.com/e-mission/cordova-server-communication/pull/33

shankari commented 4 months ago
Rebuilt but no new tag generated
Screenshot 2024-07-26 at 1 43 45 PM Screenshot 2024-07-26 at 1 44 23 PM