Page MenuHomePhabricator

ZppixBot-test fails restarts correctly on python 3.7 after crash
Closed, InvalidPublic3 Estimated Story Points

Description

12:33:16 <ZppixBot-test> [2020-06-03 11:32:21,461] sopel.irc.backends  ERROR    - Server timeout detected after 202s; closing.
12:33:16 ⇐︎ + ZppixBot-test quit (~ZppixBot@miraheze/bot/Zppix): Read error: Connection reset by peer

90 mins later and I’ve got back to it still down

Event Timeline

RhinosF1 triaged this task as Unbreak Now! priority.Jun 3 2020, 1:09 PM
RhinosF1 created this task.
Restricted Application added subscribers: Reception123, Liuxinyu970226, Zppix, Aklapper. · View Herald Transcript

Logs seem to just show a complete refusal to start, attempting to recover now.

RhinosF1 lowered the priority of this task from Unbreak Now! to High.Jun 3 2020, 1:27 PM

Back online, nothing unusual in the logs but it just refused to start up after the timeout

Twitter + urls remain disabled due to this on -test

DO NOT ROLL OUT 3.7

RhinosF1 renamed this task from ZppixBot Test Instance down to ZppixBot-test starts improperly on python 3.7.Jun 3 2020, 2:44 PM

This is bad enough that we might need to consider rolling back but I can’t do that until tonight.

RhinosF1 raised the priority of this task from High to Unbreak Now!.Jun 3 2020, 5:42 PM

We can’t deploy safely without it.

Mentioned in SAL (#wikimedia-cloud) [2020-06-03T17:58:37Z] <RhinosF1> rolling back to python 3.5 with examknow due to T254348 cc T254246

Mentioned in SAL (#wikimedia-cloud) [2020-06-03T18:15:25Z] <RhinosF1> python is now 3.5 due to T254348 cc T254246

RhinosF1 lowered the priority of this task from Unbreak Now! to High.Jun 3 2020, 6:17 PM

Rollback complete in 16 minutes and 49 seconds.

I plan tonight to fall our urls module back to core and then test turning twitter back on.

I will then try and get an api key and see what happens.

This should fix it.

RhinosF1 lowered the priority of this task from High to Medium.Jun 6 2020, 11:31 AM
RhinosF1 moved this task from Unbreak Now! to 2020 June - September on the ZppixBot board.
RhinosF1 set the point value for this task to 3.

We have switched urls on both instances to the upstream version.

I will be deploying twitter back on test and master by tommorow morning

Mentioned in SAL (#wikimedia-cloud) [2020-06-07T21:44:31Z] <RhinosF1> remove old url config and add twitter api keys to fix T254348 - also disable reload at same tome

Mentioned in SAL (#wikimedia-cloud) [2020-06-07T21:44:31Z] <RhinosF1> remove old url config and add twitter api keys to fix T254348 - also disable reload at same tome

Now live on -test

I will deploy to master in the morning and then we can resolve this

Mentioned in SAL (#wikimedia-cloud) [2020-06-08T08:19:22Z] <RhinosF1> restarting to apply changes for T254348

I think I fixed every error I found, logs seem clean, and the broken modules seem un-broke.

RhinosF1 raised the priority of this task from Medium to Unbreak Now!.

05:45:52 <ZppixBot-test> [2020-06-09 04:45:51,347] sopel.irc.backends  ERROR    - Server timeout detected after 121s; closing.
05:46:22 ⇐︎ ZppixBot-test quit (~ZppixBot@miraheze/bot/Zppix): Remote host closed the connection

I will capture logs and bring it back in about 90 mins

My IRC logs also show a crash lasting 32 mins over night.

RhinosF1 renamed this task from ZppixBot-test starts improperly on python 3.7 to ZppixBot-test fails restarts correctly on python 3.7 after crash.Jun 9 2020, 6:36 AM

Mentioned in SAL (#wikimedia-cloud) [2020-06-09T08:03:57Z] <RhinosF1> investigating incident T254348

[2020-06-09 04:45:51,347] sopel.irc.backends   ERROR    - Server timeout detected after 121s; closing.
[2020-06-09 04:45:51,388] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:45:51,389] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:45:52,018] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:45:52,019] sopel.bot            INFO     - Calling shutdown for 6 plugins.
[2020-06-09 04:45:56,148] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:21,386] sopel.cli.run        WARNING  - Disconnected. Reconnecting in 20 seconds...
[2020-06-09 04:46:21,386] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:21,386] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:21,387] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:21,387] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:21,387] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:21,393] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.393777. Message was: [2020-06-09 04:46:21,386] sopel.cli.run        WARNING  - Disconnected. Reconnecting in 20 seconds...
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:21,420] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:21,420] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:21,420] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:21,420] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:21,420] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:21,429] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.429112. Message was: [2020-06-09 04:46:21,393] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.393777. Message was: [2020-06-09 04:46:21,386] sopel.cli.run        WARNING  - Disconnected. Reconnecting in 20 seconds...Traceback (most recent call last):  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call    exit_code = func(sopel, trigger)  File "/data/project/zppixbot-test/zppixbottest37/
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:21,430] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:21,430] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:21,430] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:21,430] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:21,430] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:21,437] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.437726. Message was: [2020-06-09 04:46:21,429] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.429112. Message was: [2020-06-09 04:46:21,393] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.393777. Message was: [2020-06-09 04:46:21,386] sopel.cli.run        WARNING  - Disconnected. Reconnecting in 20 seconds...Traceback (most recent call last):  File "/data/project/zppixbot-test/zppixbott
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:23,440] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:23,440] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:23,440] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:23,440] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:23,440] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:23,448] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:23.448177. Message was: [2020-06-09 04:46:21,437] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.437726. Message was: [2020-06-09 04:46:21,429] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.429112. Message was: [2020-06-09 04:46:21,393] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.393777. Message was: [2020-06-09 04:46:21,386] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:25,448] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:25,449] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:25,449] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:25,449] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:25,449] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:25,456] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:25.455975. Message was: [2020-06-09 04:46:23,448] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:23.448177. Message was: [2020-06-09 04:46:21,437] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.437726. Message was: [2020-06-09 04:46:21,429] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.429112. Message was: [2020-06-09 04:46:21,393] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:27,458] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:27,459] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:27,459] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:27,459] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:27,459] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:27,466] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:27.466870. Message was: [2020-06-09 04:46:25,456] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:25.455975. Message was: [2020-06-09 04:46:23,448] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:23.448177. Message was: [2020-06-09 04:46:21,437] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:21.437726. Message was: [2020-06-09 04:46:21,429] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:29,469] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:29,469] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:29,469] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:29,469] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:29,469] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:29,474] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:29.474374. Message was: [2020-06-09 04:46:27,466] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:27.466870. Message was: [2020-06-09 04:46:25,456] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:25.455975. Message was: [2020-06-09 04:46:23,448] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:23.448177. Message was: [2020-06-09 04:46:21,437] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:31,476] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:31,476] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:31,476] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:31,476] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:31,477] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:31,483] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:31.483606. Message was: [2020-06-09 04:46:29,474] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:29.474374. Message was: [2020-06-09 04:46:27,466] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:27.466870. Message was: [2020-06-09 04:46:25,456] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:25.455975. Message was: [2020-06-09 04:46:23,448] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:33,485] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:33,485] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:33,485] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:33,485] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:33,485] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:33,496] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:33.496444. Message was: [2020-06-09 04:46:31,483] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:31.483606. Message was: [2020-06-09 04:46:29,474] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:29.474374. Message was: [2020-06-09 04:46:27,466] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:27.466870. Message was: [2020-06-09 04:46:25,456] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:35,499] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:35,499] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:35,499] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:35,499] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:35,499] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:35,507] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:35.507173. Message was: [2020-06-09 04:46:33,496] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:33.496444. Message was: [2020-06-09 04:46:31,483] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:31.483606. Message was: [2020-06-09 04:46:29,474] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:29.474374. Message was: [2020-06-09 04:46:27,466] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:37,509] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:37,510] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:37,510] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:37,510] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:37,510] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:37,517] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:37.517694. Message was: [2020-06-09 04:46:35,507] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:35.507173. Message was: [2020-06-09 04:46:33,496] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:33.496444. Message was: [2020-06-09 04:46:31,483] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:31.483606. Message was: [2020-06-09 04:46:29,474] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:39,520] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:39,520] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:39,520] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:39,520] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:39,520] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:39,527] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:39.527121. Message was: [2020-06-09 04:46:37,517] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:37.517694. Message was: [2020-06-09 04:46:35,507] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:35.507173. Message was: [2020-06-09 04:46:33,496] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:33.496444. Message was: [2020-06-09 04:46:31,483] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:41,529] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:41,529] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:41,529] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:41,529] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:41,529] sopel.irc.backends   INFO     - Closed!
[2020-06-09 04:46:41,535] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:41.535755. Message was: [2020-06-09 04:46:39,527] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:39.527121. Message was: [2020-06-09 04:46:37,517] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:37.517694. Message was: [2020-06-09 04:46:35,507] sopel.bot            ERROR    - Unexpected error ('find_lines') from ZppixBot-test at 2020-06-09 04:46:35.507173. Message was: [2020-06-09 04:46:33,496] s
Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'
[2020-06-09 04:46:43,538] sopel.irc.backends   INFO     - Connection closed...
[2020-06-09 04:46:43,538] sopel.bot            INFO     - Stopping the Job Scheduler.
[2020-06-09 04:46:43,539] sopel.bot            INFO     - Job Scheduler stopped.
[2020-06-09 04:46:43,539] sopel.bot            INFO     - Calling shutdown for 0 plugins.
[2020-06-09 04:46:43,539] sopel.irc.backends   INFO     - Closed!
tools.zppixbot-test@tools-sgebastion-07:~$

find.py doesn't make sense as nothing touches the memory on our end and I don't have a clue yet why the Connection immdiately closed but exact same error as last time.

Traceback (most recent call last):
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/bot.py", line 606, in call
    exit_code = func(sopel, trigger)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/module.py", line 495, in guarded
    return function(bot, trigger, *args, **kwargs)
  File "/data/project/zppixbot-test/zppixbottest37/lib/python3.7/site-packages/sopel/modules/find.py", line 43, in collectlines
    if trigger.sender not in bot.memory['find_lines']:
KeyError: 'find_lines'

I'm going to have to try and debug before I restart it so it could be another half an hour before -test is back.

I'll check logs again after but we may need to roll back.

I'm going to have to try and debug before I restart it so it could be another half an hour before -test is back.

I'll check logs again after but we may need to roll back.

Issue is being looked at upstream so I'm now waiting on rollback or reboot advice

RhinosF1 moved this task from Backlog to Reported Upstream on the Upstream board.

https://github.com/sopel-irc/sopel/issues/1868 would have been the original cause,

https://github.com/sopel-irc/sopel/issues/1865 is the find_lines issue

about to open a bug for this actual issue to see what they can do

I plan to roll this back to python 3.5

Mentioned in SAL (#wikimedia-cloud) [2020-06-09T09:41:45Z] <RhinosF1> delete deployment to begin rolling back T254246 due to T254348

Mentioned in SAL (#wikimedia-cloud) [2020-06-09T09:47:14Z] <RhinosF1> rolled back sopelbot to python 3.5 -- END due to T254348 (cc T254246)

RhinosF1 changed the task status from Open to Stalled.Jun 9 2020, 9:51 AM
RhinosF1 lowered the priority of this task from Unbreak Now! to Medium.

Blocked on upstream.

RhinosF1 awarded a token.

Mentioned in SAL (#wikimedia-cloud) [2020-06-09T21:17:23Z] <RhinosF1> - messing stuff up to test T254348

Mentioned in SAL (#wikimedia-cloud) [2020-06-09T21:44:55Z] <RhinosF1> keeping logging_channel off with debug logs and hoping the bot timesout to get some decent non log spammed logs to try and fix bug 2/3 in T254348

I've confirmed and updated upstream with the cause of https://github.com/sopel-irc/sopel/issues/1865 with high confidence and set some config to get us decent logs for https://github.com/sopel-irc/sopel/issues/1868.

Hopefully, if we fix them, https://github.com/sopel-irc/sopel/issues/1888 will become mute.

So we should have a fix by Sopel 7.1

When 1865 and 1868 get fixed, they are still ways to test 1888 but it should be less of an issue.

This may have been fixed, monitoring until Sunday then will deploy & test.

RhinosF1 changed the task status from Stalled to Open.Jun 19 2020, 2:28 PM

no blockers are actually upstream

Broken cache, resolved