[$150] Lots of ID null logs

[jmgasper]

@afrisalyp - We finally got the latest code deployed in prod. I'm seeing this a lot for Github tickets in the logs:

error: Error happened in process
TypeError: Cannot read property 'id' of null
    at handleIssueLabelUpdated (/topcoder-x-processor/services/IssueService.js:578:47)
    at <anonymous>
    at process._tickDomainCallback (internal/process/next_tick.js:229:7)
error:  message=Cannot read property 'id' of null, stack=TypeError: Cannot read property 'id' of null
    at handleIssueLabelUpdated (/topcoder-x-processor/services/IssueService.js:578:47)
    at <anonymous>
    at process._tickDomainCallback (internal/process/next_tick.js:229:7), logged=true

It doesn't seem to affect functionality, but it's something we should clean up, thanks.

[jmgasper]

@afrisalyp - Can you take a look at this one please? I'm also seeing stuff like this, which seems to be similar:

debug: received message from kafka: {"topic":"topcoder-x","originator":"topcoder-x-receiver","timestamp":"2019-11-21T19:52:53.263Z","mime-type":"application/json","payload":{"value":"{\"event\":\"issue.updated\",\"provider\":\"github\",\"data\":{\"issue\":{\"number\":48,\"body\":\"Double click doesn't open edit substation popup\",\"title\":\"[$40] - Double click doesn't open edit substation popup\",\"labels\":[],\"assignees\":[],\"owner\":{\"id\":5815182}},\"repository\":{\"id\":221569487,\"name\":\"ABB_TaaS\",\"full_name\":\"topcoderinc/ABB_TaaS\"}}}"}}
debug: ENTER process
debug: input arguments
debug: { event:
   { event: 'issue.updated',
     provider: 'github',
     data: { issue: [Object], repository: [Object] } } }
debug: ENTER getRepositoryCopilotOrOwner
debug: input arguments
debug: { provider: 'github', repoFullName: 'topcoderinc/ABB_TaaS' }
debug: EXIT getRepositoryCopilotOrOwner
debug: output arguments
debug: { accessToken: '<removed>',
  userProviderId: 21790,
  topcoderUsername: 'ghostar' }
debug: ENTER handleEventGracefully
debug: input arguments
debug: { event:
   { event: 'issue.updated',
     provider: 'github',
     data: { issue: [Object], repository: [Object] },
     copilot:
      { accessToken: '<removed>',
        userProviderId: 21790,
        topcoderUsername: 'ghostar' } },
  data:
   { number: 48,
     title: '- Double click doesn\'t open edit substation popup',
     body: '<p>Double click doesn\'t open edit substation popup</p>\n',
     provider: 'github',
     repositoryId: 221569487,
     labels: [],
     projectId: '0bbcd55c-22ee-4c34-91af-e8bd0e10307a-1574306819630',
     prizes: [ 40 ] },
  err: {} }
error: Error happened in handleEventGracefully
TypeError: Cannot read property 'title' of null
    at handleIssueUpdate (/topcoder-x-processor/services/IssueService.js:296:17)
    at <anonymous>
    at process._tickDomainCallback (internal/process/next_tick.js:229:7)
error:  message=Cannot read property 'title' of null, stack=TypeError: Cannot read property 'title' of null
    at handleIssueUpdate (/topcoder-x-processor/services/IssueService.js:296:17)
    at <anonymous>
    at process._tickDomainCallback (internal/process/next_tick.js:229:7), logged=true

[jmgasper]

Contest https://www.topcoder-dev.com/challenges/30107632 has been created for this ticket.

This is an automated message for ghostar via Topcoder X

[jmgasper]

Contest https://www.topcoder-dev.com/challenges/30107633 has been created for this ticket.

This is an automated message for ghostar via Topcoder X

[jmgasper]

Contest https://www.topcoder-dev.com/challenges/30107634 has been created for this ticket.

This is an automated message for ghostar via Topcoder X

[afrisalyp]

@jmgasper
I think this issue is related to the duplicate issue. The main problem is we got null when we get the dbIssue.

https://github.com/topcoder-platform/topcoder-x-processor/blob/develop/services/IssueService.js#L66

That's also why the processor does create process again. (Related to the duplicate issue)

Can you please try to put some log to the line code to print out the params in the production?

• issue.number
• issue.provider
• issue.repositoryId

[jmgasper]

@afrisalyp - I'll do that now. In the meantime, I dumped the issues table if you want to take a look. I'll email you directly so it's not in the public Github repo.

[afrisalyp]

@jmgasper
Okay, thanks.

[afrisalyp]

@jmgasper
I found this ticket has 4 records in the dumped issues table.
One of the records is pending.

         {
            "projectId": {
                "S": "4eeb7236-6721-4bc0-99b1-fabda68f2dee-1574306795229"
            },
            "number": {
                "N": "232"
            },
            "repositoryId": {
                "N": "135514613"
            },
            "labels": {
                "SS": [
                    "tcx_OpenForPickup"
                ]
            },
            "updatedAt": {
                "N": "1574330174119"
            },
            "status": {
                "S": "challenge_creation_pending"
            },
            "provider": {
                "S": "github"
            },
            "id": {
                "S": "591c4ab8-f810-4f42-b7bf-9c81a15c3f14-1574330174119"
            },
            "prizes": {
                "NS": [
                    "50"
                ]
            },
            "title": {
                "S": "Lots of ID null logs"
            },
            "body": {
                "S": "<p>@afrisalyp - We finally got the latest code deployed in prod.  I'm seeing this a lot for Github tickets in the logs:</p>\n<pre><code>error: Error happened in process\nTypeError: Cannot read property 'id' of null\n    at handleIssueLabelUpdated (/topcoder-x-processor/services/IssueService.js:578:47)\n    at &lt;anonymous&gt;\n    at process._tickDomainCallback (internal/process/next_tick.js:229:7)\nerror:  message=Cannot read property 'id' of null, stack=TypeError: Cannot read property 'id' of null\n    at handleIssueLabelUpdated (/topcoder-x-processor/services/IssueService.js:578:47)\n    at &lt;anonymous&gt;\n    at process._tickDomainCallback (internal/process/next_tick.js:229:7), logged=true\n</code></pre>\n<p>It doesn't seem to affect functionality, but it's something we should clean up, thanks.</p>\n"
            }
        },

Can you please check the record again so we know if the record is still pending or something else status.
Thanks.

[jmgasper]

@afrisalyp - That's not great. Any idea how we could end up with 4 records?

[afrisalyp]

This ticket has three challenge creation comments, but the records in the DB is four.

#232 (comment)
#232 (comment)
#232 (comment)

As we saw, one of the record is challenge_creation_pending
This might be a possible cause. The dbHelper.scanOne function always returns the pending record. So it always does the reschedule mechanism.
Still investigating this.

[jmgasper]

Contest https://www.topcoder.com/challenges/30108139 has been created for this ticket.

This is an automated message for ghostar via Topcoder X

[jmgasper]

This ticket was not processed for payment. If you would like to process it for payment, please reopen it, add the tcx_FixAccepted label, and then close it again

This is an automated message for ghostar via Topcoder X

[jmgasper]

Contest https://www.topcoder.com/challenges/30108139 has been updated - it has been assigned to afrisalyp.

This is an automated message for ghostar via Topcoder X

[jmgasper]

Payment task has been updated: https://software.topcoder-dev.com/review/actions/ViewProjectDetails?pid=30108139

This is an automated message for ghostar via Topcoder X