Some schedule messages still not parsing
Closed this issue · 10 comments
Examples:
@joecupojoe @carbon752 7/30 13:30
@joecupojoe vs @carbon752 7/30 13:30
@joecupojoe @carbon752 7/30 @ 13:30 GMT
@joecupojoe vs @carbon752 7/30 @ 13:30 GMT
``
MOAR:
@heidman vs @icendoan 7/30 @ 10:30
for us or for slack - idk. but labeling as a bug for now
`Logs from the most recent error:
Message: @durchnachtundwind vs @juldiaz280992 Wednesday @ 20:30
Trace:
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 1. Detecting Scheduling message
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 3. Checking Channel
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 5. Checking Scheduling Options
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 6. Checking Spreadsheet Options
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 7. Checking if channel is in schedulingOptions
debug: [RESULTS][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 1. Checking for League
debug: [RESULTS][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 2. Checking for channel
debug: [RESULTS][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 3. Checking for spreadsheetOptions
debug: [RESULTS][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 4. Checking for resultsOptions
debug: [GAMELINK][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 1. Detecting gamelink
debug: [GAMELINK][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 2. checking for appropriate channel
debug: [GAMELINK][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 3. checking for spreadsheetOptions
debug: [GAMELINK][Message: <@U0J120KAA> vs <@U0UMSDV9A> 08/03 20:30 GMT]: 4. checking for gamelinkOptions
Message: @durchnachtundwind vs @juldiaz280992 08/03 20:30 GMT
Trace:
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 1. Detecting Scheduling message
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 3. Checking Channel
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 5. Checking Scheduling Options
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 6. Checking Spreadsheet Options
debug: [Scheduling][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 7. Checking if channel is in schedulingOptions
debug: [RESULTS][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 1. Checking for League
debug: [RESULTS][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 2. Checking for channel
debug: [RESULTS][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 3. Checking for spreadsheetOptions
debug: [RESULTS][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 4. Checking for resultsOptions
debug: [GAMELINK][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 1. Detecting gamelink
debug: [GAMELINK][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 2. checking for appropriate channel
debug: [GAMELINK][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 3. checking for spreadsheetOptions
debug: [GAMELINK][Message: <@U0J120KAA> vs <@U0UMSDV9A> Wednesday @ 20:30]: 4. checking for gamelinkOptions
I need to compare this to the code but this looks healthy, right?
It just randomly stops after point 7, which doesn't make any sense. That check shouldn't fail under normal circumstances: https://github.com/endrawes0/Chesster/blob/master/src/chesster.js#L570
My PR will add logging of the channel.name and scheduleOptions.channel - I'm hoping that proves my suspicion.
My suspicion at this point is that we have a concurrency issue where two calls to the same thing result in the first call having some global state overwritten. And somehow that results in the if statement failing.
Although if it truly was a race condition, seeing it happen twice in a row should have been reasonably rare - unless it depends on some other data that was in the middle of being refreshed at the time.
debug: [Scheduling][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 1. Detecting Scheduling message
Raw log from another instance:
debug: [Scheduling][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 3. Checking Channel
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [Scheduling][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 5. Checking Scheduling Options
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [Scheduling][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 6. Checking Spreadsheet Options
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [Scheduling][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 7. Checking if channel is in schedulingOptions: team-scheduling vs lonewolf-scheduling
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [RESULTS][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 1. Checking for League
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [RESULTS][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 2. Checking for channel
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [RESULTS][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 3. Checking for spreadsheetOptions
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [RESULTS][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 4. Checking for resultsOptions
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [GAMELINK][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 1. Detecting gamelink
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [GAMELINK][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 2. checking for appropriate channel
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [GAMELINK][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 3. checking for spreadsheetOptions
info: *\* API CALL: https://slack.com/api/chat.postMessage
debug: [GAMELINK][Message: @U1MFA50DT v @U0SSA2F6K 8/4 23:30 GMT]: 4. checking for gamelinkOptions
It's the XX:30 games that are failing, because my fuzzy matching thinks that XX:30 is really close to 30+30 and thinks they are talking about lonewolf, so it sets up the league for that message to be the lonewolf league so that if statement fails.
Working on a solution.
Indeed all examples here are XX:30.
How did we miss that?
I really don't know how we missed that. However, some XX:30 ones are working. I think it's any that have a 3 in the first part, so 23:30, 13:30, cause the rule I'm using is if there is less than have of the characters need to be changed to get from a string to 30+30, and 23:30 only has to change 2 characters to get to 30+30.