Page MenuHomePhabricator

-user global argument ignored breaks test suite
Closed, ResolvedPublic

Description

A lot of travis tests failes:

======================================================================
FAIL: test_welcome (tests.script_tests.TestScriptHelp)
Test running welcome -help.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/travis/build/wikimedia/pywikibot-core/tests/script_tests.py", line 295, in testScript
    stderr_other)
AssertionError: u'Use -help for further information.' not found in [u'No handlers could be found for logger "pywiki"', u'']

See for example https://travis-ci.org/wikimedia/pywikibot-core/jobs/112380516

Breakage occurred with February 13 (20c9ab1b) and fixed March 8.

Event Timeline

jayvdb renamed this task from No handlers could be found for logger "pywiki to No handlers could be found for logger "pywiki".Mar 6 2016, 1:19 AM
jayvdb updated the task description. (Show Details)

According to git bisect, there was a regression introduced by 20c9ab1b16df, which merged 665d824e4 , which is https://gerrit.wikimedia.org/r/#/c/268962/

On all Python versions, it caused all scripts -help to output

AssertionError: 'Use -help for further information.' not found in ['family and mylang are not set.', "Defaulting to family='test' and mylang='test'.", '']

One part of the problem was fixed with f0e2104d (on all versions of Python, not only py2.6), however the error then changed to the current error on all Python versions

AssertionError: u'Use -help for further information.' not found in [u'No handlers could be found for logger "pywiki"', u'']

Change 275776 had a related patch set uploaded (by John Vandenberg):
Revert "[IMPR] Simplify arg parsing in handle_args method"

https://gerrit.wikimedia.org/r/275776

Hm, I don't see the point why the logger was missing. Could you give me a hint.

I don't have the logger bug in my script tests. We should explore the reals cause.

C:\pwb\GIT\core>pwb.py tests/script_tests TestScriptHelp
tests: max_retries reduced from 25 to 1
match_images depends on PIL.ImageTk, which isnt available:
No module named PIL.ImageTk
imageharvest depends on BeautifulSoup, which isnt available:
No module named BeautifulSoup
data_ingestion depends on unicodecsv, which isnt available:
No module named unicodecsv
panoramiopicker depends on BeautifulSoup, which isnt available:
No module named BeautifulSoup
script_wui depends on crontab, which isnt available:
No module named crontab
patrol depends on mwparserfromhell, which isnt available:
No module named mwparserfromhell
states_redirect depends on pycountry, which isnt available:
No module named pycountry
flickrripper depends on flickrapi, which isnt available:
No module named flickrapi
....................x......x......x.........x......xx.......x.....x..F.....F...
======================================================================
FAIL: test_test (__main__.TestScriptHelp)
Test running test -help.
----------------------------------------------------------------------
Traceback (most recent call last):
  File ".\tests\script_tests.py", line 300, in testScript
    result['stdout'])
AssertionError: u'Global arguments available for all' not found in u'[[Benutzer:
Xqt]]\r\n'

======================================================================
FAIL: test_version (__main__.TestScriptHelp)
Test running version -help.
----------------------------------------------------------------------
Traceback (most recent call last):
  File ".\tests\script_tests.py", line 296, in testScript
    stderr_other)
AssertionError: u'Use -help for further information.' not found in [u'Pywikibot:
 [ssh] pywikibot-core (2d24ee8, g7068, 2016/03/08, 07:34:38, ok)', u'Release ver
sion: 3.0-dev', u'requests version: 2.7.0', u'  cacerts: C:\\Python27\\lib\\site
-packages\\requests\\cacert.pem', u'    certificate test: ok', u'Python: 2.7.9 (
default, Dec 10 2014, 12:24:55) [MSC v.1500 32 bit (Intel)]', u'PYWIKIBOT2_DIR:
C:\\pwb\\GIT\\core', u'PYWIKIBOT2_DIR_PWB: ', u'PYWIKIBOT2_NO_USER_CONFIG: Not s

@Xqt , To reproduce you need a clean user-config.py . See .travis.yml, which does

python -W error::UserWarning -m generate_user_files -dir:~/.pywikibot/ -family:$FAMILY -lang:$LANGUAGE -v -user:"$PYWIKIBOT2_USERNAME"
# add more usernames to ~/.pywikibot/user-config.py
echo "max_retries = 2" >> ~/.pywikibot/user-config.py
echo "maximum_GET_length = 5000" >> ~/.pywikibot/user-config.py
echo "console_encoding = 'utf8'" >> ~/.pywikibot/user-config.py

Was unable to reproduce it with neither clean user-config.py

mylang = 'en'
family = 'wikipedia'
usernames['wikipedia']['en'] = 'Test'
max_retries = 2
maximum_GET_length = 5000
console_encoding = 'utf8'

nor with autogenerated user-config.py with these 3 additional lines :(

I can reproduce with

$ cat user-config.py
import os

usernames['wikipedia']['en'] = 'JVbot-test'
usernames['wikisource']['en'] = 'JVbot-test'
usernames['wikipedia']['test'] = 'JVbot-test'
usernames['wikidata']['test'] = 'JVbot-test'
usernames['test']['test'] = 'JVbot-test'

password_file = os.path.expanduser('~/.pywikibot/passwordfile')
$ python -m unittest -v tests.script_tests.TestScriptHelp.test_add_text
No handlers could be found for logger "pywiki"
tests: max_retries reduced from 25 to 1
script_wui depends on lua, which isnt available:
No module named lua
test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help. ... FAIL

======================================================================
FAIL: test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "tests/script_tests.py", line 296, in testScript
    stderr_other)
AssertionError: u'Use -help for further information.' not found in [u'No handlers could be found for logger "pywiki"']

----------------------------------------------------------------------
Ran 1 test in 8.688s

FAILED (failures=1)

Now the interesting part ... the revert doesnt work for me (but it clearly fixes Travis builds), and the result array has changed to add an extra element u''.

$ git review -d 275776
Downloading refs/changes/76/275776/2 from gerrit
Switched to branch "review/john_vandenberg/handle_args"
$ python -m unittest -v tests.script_tests.TestScriptHelp.test_add_text
No handlers could be found for logger "pywiki"
tests: max_retries reduced from 25 to 1
script_wui depends on lua, which isnt available:
No module named lua
test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help. ... FAIL

======================================================================
FAIL: test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "tests/script_tests.py", line 295, in testScript
    stderr_other)
AssertionError: u'Use -help for further information.' not found in [u'No handlers could be found for logger "pywiki"', u'']

----------------------------------------------------------------------
Ran 1 test in 8.679s

FAILED (failures=1)

and on Python 3.4 with the revert patch

$ python3.4 -m unittest -v tests.script_tests.TestScriptHelp.test_add_text
family and mylang are not set.
Defaulting to family='test' and mylang='test'.
tests: max_retries reduced from 25 to 1
match_images depends on PIL.ImageTk, which isnt available:
No module named 'PIL.ImageTk'
script_wui depends on crontab, which isnt available:
No module named 'crontab'
flickrripper depends on flickrapi, which isnt available:
No module named 'flickrapi'
states_redirect depends on pycountry, which isnt available:
No module named 'pycountry'
imageharvest depends on BeautifulSoup, which isnt available:
No module named 'BeautifulSoup'
panoramiopicker depends on BeautifulSoup, which isnt available:
No module named 'BeautifulSoup'
patrol depends on mwparserfromhell, which isnt available:
No module named 'mwparserfromhell'
test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help. ... FAIL

======================================================================
FAIL: test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/.../tests/script_tests.py", line 295, in testScript
    stderr_other)
AssertionError: 'Use -help for further information.' not found in ['family and mylang are not set.', "Defaulting to family='test' and mylang='test'.", '']

----------------------------------------------------------------------
Ran 1 test in 3.297s

FAILED (failures=1)

It is not finding my user-config.py

depends on config setting:
First try with empty user-config.py; the error message is on the first line

C:\pwb\GIT\core>python.exe -m unittest -v tests.script_tests.TestScriptHelp.test
_add_text
No handlers could be found for logger "pywiki"
tests: max_retries reduced from 25 to 1
match_images depends on PIL.ImageTk, which isnt available:
No module named PIL.ImageTk
imageharvest depends on BeautifulSoup, which isnt available:
No module named BeautifulSoup
data_ingestion depends on unicodecsv, which isnt available:
No module named unicodecsv
panoramiopicker depends on BeautifulSoup, which isnt available:
No module named BeautifulSoup
script_wui depends on crontab, which isnt available:
No module named crontab
patrol depends on mwparserfromhell, which isnt available:
No module named mwparserfromhell
states_redirect depends on pycountry, which isnt available:
No module named pycountry
flickrripper depends on flickrapi, which isnt available:
No module named flickrapi
test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help. ... FAIL

======================================================================
FAIL: test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help.
----------------------------------------------------------------------
Traceback (most recent call last):
  File "tests\script_tests.py", line 296, in testScript
    stderr_other)
AssertionError: u'Use -help for further information.' not found in [u'No handler
s could be found for logger "pywiki"']

----------------------------------------------------------------------
Ran 1 test in 0.950s

FAILED (failures=1)

2nd try with my standard user-config.py

C:\pwb\GIT\core>python.exe -m unittest -v tests.script_tests.TestScriptHelp.test
_add_text
tests: max_retries reduced from 25 to 1
match_images depends on PIL.ImageTk, which isnt available:
No module named PIL.ImageTk
imageharvest depends on BeautifulSoup, which isnt available:
No module named BeautifulSoup
data_ingestion depends on unicodecsv, which isnt available:
No module named unicodecsv
panoramiopicker depends on BeautifulSoup, which isnt available:
No module named BeautifulSoup
script_wui depends on crontab, which isnt available:
No module named crontab
patrol depends on mwparserfromhell, which isnt available:
No module named mwparserfromhell
states_redirect depends on pycountry, which isnt available:
No module named pycountry
flickrripper depends on flickrapi, which isnt available:
No module named flickrapi
test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help. ... ok

----------------------------------------------------------------------
Ran 1 test in 0.971s

OK

C:\pwb\GIT\core>

Ah! Seems mylang is missing.
If I use an user-config.py with this single entry:

mylang= 'de'

it works for me.

Another try to verify:

C:\pwb\GIT\core>python.exe -m unittest -v tests.script_tests.TestScriptHelp.test
_add_text
No handlers could be found for logger "pywiki"
tests: max_retries reduced from 25 to 1
...
test_add_text (tests.script_tests.TestScriptHelp)
Test running add_text -help -lang:de. ... ok

----------------------------------------------------------------------
Ran 1 test in 1.047s

Fails for a wrong language code too.

Change 275799 had a related patch set uploaded (by Xqt):
[Bugfix] compare "-user" instead of "-user:"

https://gerrit.wikimedia.org/r/275799

Change 275799 merged by jenkins-bot:
[Bugfix] compare "-user" instead of "-user:"

https://gerrit.wikimedia.org/r/275799

Change 275776 abandoned by John Vandenberg:
Revert "[IMPR] Simplify arg parsing in handle_args method"

Reason:
thx for finding the bug xqt

https://gerrit.wikimedia.org/r/275776

Xqt claimed this task.
jayvdb renamed this task from No handlers could be found for logger "pywiki" to -user argument ignored.Mar 21 2016, 9:15 AM
jayvdb renamed this task from -user argument ignored to -user global argument ignored breaks test suite.
jayvdb triaged this task as Unbreak Now! priority.
jayvdb updated the task description. (Show Details)