bcgov / entity

ServiceBC Registry Team working on Legal Entities
Apache License 2.0
23 stars 57 forks source link

Production NR stuck in nro-update #49

Closed WalterMoar closed 5 years ago

WalterMoar commented 5 years ago

Describe the bug

On 2018-12-04 at 12:21, NR 1843266 started to producing an error every minute when the nro-update job runs. The error is:

2018-12-05 16:18:20,421 - flask.app - DEBUG in nro_update:nro_update.py:78 - : processing: NR 1843266 2018-12-05 16:18:20,421 - flask.app - DEBUG in nro_datapump:nro_datapump.py:24 - nro_data_pump_update: processing names for :NR 1843266 2018-12-05 16:18:20,431 - flask.app - ERROR in nro_update:nro_update.py:90 - : 'NoneType' object is not subscriptable 2018-12-05 16:18:20,431 - flask.app - ERROR in nro_update:nro_update.py:91 - : ERROR: NR 1843266

The problem is that line 44 of nro_datapump.py is failing when it tries to take a subscript of a NULL conflict1_num in the database:

        nro_names[choice]['conflict1'] = '{}****{}'.format(_clear_NR_num_from_conflict(name.conflict1_num[:10]), name.conflict1[:150])

To Reproduce see NR 2652523 in TEST. 1) Select a conflict on a draft name and reject 2) Wait for decision to move back to NRO 3) Reset the name and approve the same name choice that previously had a rejection conflict 4) You should see the error as some vestige of the old conflict is sent back along with the new approval.

Expected behavior There should have been a conflict1_num value for the name. With this, the NR would have been processed by nro-update without error.

Additional context Due to this being a production problem, the missing conflict1_num value of "BC 0537305" was added to the postgres database:

UPDATE names SET conflict1_num = 'BC 0537305' WHERE id = 3582115 AND name = 'GREEN GAIA HEMP CO.' AND conflict1_num IS NULL;

WalterMoar commented 5 years ago

This happened again in production on December 20th 2018 at 10:47 for NR 9945031.

WalterMoar commented 5 years ago

This happened again in production on January 18th, 2019 at 09:40 for NR 9873928 (priority).

WalterMoar commented 5 years ago

This happened again in production on January 21st 2019 at 16:23:07.941 for NR 7107720.

WalterMoar commented 5 years ago

This happened again in production on January 22nd 2019 at 08:47:27.035 for NR 7107720. This happened again in production on January 22nd 2019 at 08:57:23.418 for NR 9525145.

WalterMoar commented 5 years ago

This happened again in production on January 22nd 2019 at 10:32:19.756 for NR 4747716.

WalterMoar commented 5 years ago

This happened again in production on January 23rd 2019 at 11:09:19.976 for NR 0463303.

WalterMoar commented 5 years ago

This happened again in production on January 23rd 2019 at 13:52:51.666 for NR 9619234.

WalterMoar commented 5 years ago

This happened again in production on January 24th 2019 at 10:55:25.744 for NR 8320889.

pwei1018 commented 5 years ago

This happened again in production on January 25th 2019 at 14:06:40 for NR 6393825.

WalterMoar commented 5 years ago

This happened again in production on January 28th 2019 at 09:00:23.336 for NR 0640006.

WalterMoar commented 5 years ago

This happened again in production on January 28th 2019 at 11:21:18.700 for NR 6179708.

WalterMoar commented 5 years ago

This happened again in production on January 29th 2019 at 14:58:25.597 for NR 0831003.

WalterMoar commented 5 years ago

This happened again in production on January 29th 2019 at 16:16:19.081 for NR 6643310.

WalterMoar commented 5 years ago

This happened again in production on January 30th 2019 at 10:57:32.819 for NR 0490134.

WalterMoar commented 5 years ago

This happened again in production on January 30th 2019 on 11:15:27.495 for NR 7927600.

WalterMoar commented 5 years ago

This happened again in production on January 30th 2019 at 15:13:23.180 for NR 9547632.

WalterMoar commented 5 years ago

This happened again in production on January 30th 2019 at 15:32:19.100 for NR 6469175.

WalterMoar commented 5 years ago

This happened again in production on January 31st 2019 at 11:24:21.471 for NR 7322029.

WalterMoar commented 5 years ago

This happened again in production on February 5th 2019 at 10:24:21.685 for NR 2079390.

WalterMoar commented 5 years ago

This happened again in production on February 5th 2019 at 11:55:22.499 for NR 1336376.

WalterMoar commented 5 years ago

This happened again in production on February 5th 2019 at 15:03:18.522 for NR 9581379.

WalterMoar commented 5 years ago

This happened again in production on 2019-02-08 at 09:26:24.438 for NR 7449588.

WalterMoar commented 5 years ago

This happened again in production on February 8th 2019 at 14:25:28.327 for NR 4124288.

WalterMoar commented 5 years ago

This happened again in production on February 11th 2019 at 11:08:27.347 for NR 8555934.

WalterMoar commented 5 years ago

This happened again in production on February 11th 2019 at 12:48:36.732 for NR 3736000.

katiemcgoff commented 5 years ago

Okay I think I found the issue, and it's front-end. The name data that is sent back upon reset is missing the conflict number, which (I think) clears the data from the name in postgres. So then when a new decision is made on a name, if there was a previous name (first or second name) that had a conflict, that data is never recreated. At this point I'm not sure how this goes back to Dec 4, when the change from blanking all decision data only went in in Jan, but I will check back and see if I can spot any other reasons this might happen. I spot checked the most recent NRs that had this issue and they all match this scenario, though.

katiemcgoff commented 5 years ago

Revised exact steps to reproduce (similar to above but not quite):

  1. Find an NR with at least two names.
  2. Reject the first name with a conflict.
  3. Approve the second name.
  4. Load another NR (unexamined) with at least one name.
  5. Reject the first name with any kind of rejection that does not have conflicts (ie: quick reject or go into the decision screen and reject, but no conflicts selected).
  6. Do whatever you like with the remaining names.
  7. Navigate back to the original NR. Reset it.

Upon loading the original NR in prep to reset it, the name 1's conflict number (conflict1_num) set to null. Therefore the reset sends null and it is cleared.

I tried various other steps to reproduce this, but we must get to a scenario where a previous NR has set the value in the store. The conflictx_num fields are inconsistently set in the store and aren't cleared/reset upon loading a new NR, so this bug requires these preconditions to reproduce. For example, if you simply log in and go straight to the NR and reset it, you won't encounter the bug because conflict1_num doesn't exist in the vue store, so isn't sent in the reset PUT, so isn't overwritten - it's left as-is by the API.

Will be fixing this with front-end changes - adding conflictX_num fields to store everywhere conflictX fields are, ie: the base structure of name, plus getting from API (loadCompanyInfo()).

WalterMoar commented 5 years ago

This happened again in production on February 13th 2019 at 10:18:21.742 for NR 9337867.

WalterMoar commented 5 years ago

This happened again in production on February 13th 2019 at 13:23:29.192 for NR 6992759.

WalterMoar commented 5 years ago

This happened again in production on February 14th 2019 at 15:54:22.199 for NR 1847199.