Page MenuHomePhabricator
Create Task
Maniphest T264235

log header in log files is written twice
Closed, ResolvedPublicBUG REPORT
Actions

Description

Log header is not written any longer.

def writelogheader():
    """
    Save additional version, system and status info to the log file in use.

    This may help the user to track errors or report bugs.
    """
    # If a http thread is not available, it's too early to print a header
    # that includes version information, which may need to query a server.
    # The http module can't be imported due to circular dependencies.
    http = sys.modules.get('pywikibot.comms.http', None)
    if not http or not hasattr(http, 'threads') or not len(http.threads):
        return

threads has been removed from http with 952665acaa9ab2dd1a78cb4a935f3b5743941913

Details

Related Changes in Gerrit:
SubjectRepoBranchLines +/-
[bugfix] Do not print log header twice in log filespywikibot/coremaster+6 -6
[bugfix] Rewrite init_handlers and RotatingFileHandlerpywikibot/coremaster+87 -42
[bugfix] fix version.get_module_filename()pywikibot/coremaster+21 -14
[bugfix] print log headerpywikibot/coremaster+15 -20
Customize query in gerrit

Related Objects

Event Timeline

Mpaa created this task.Sep 30 2020, 7:45 PM
Restricted Application added subscribers: pywikibot-bugs-list, Aklapper. · View Herald TranscriptSep 30 2020, 7:45 PM
Xqt claimed this task.Oct 2 2020, 4:19 PM
Xqt triaged this task as Medium priority.
gerritbot added a comment.Oct 2 2020, 4:44 PM

Change 631826 had a related patch set uploaded (by Xqt; owner: Xqt):
[pywikibot/core@master] [bugfix] print log header

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

gerritbot added a project: Patch-For-Review.Oct 2 2020, 4:44 PM
gerritbot added a comment.Oct 2 2020, 7:10 PM

Change 631826 merged by jenkins-bot:
[pywikibot/core@master] [bugfix] print log header

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

Xqt mentioned this in rPWBC0d1d224d8350: [bugfix] print log header.Oct 2 2020, 7:14 PM
Xqt closed this task as Resolved.Oct 2 2020, 8:03 PM
Maintenance_bot removed a project: Patch-For-Review.Oct 2 2020, 8:10 PM
Mpaa reopened this task as Open.Oct 2 2020, 8:15 PM
user@pc:~/python/core {master}$ python
Python 3.8.3 (default, Jul  2 2020, 16:21:59) 
[GCC 7.3.0] :: Anaconda, Inc. on linux
Type "help", "copyright", "credits" or "license" for more information.

>>> import pywikibot
/home/user/python/core/pywikibot/config2.py:1066: UserWarning: 
Configuration variable "oauth_tokens" is defined in your user-
config.py but unknown. It can be a misspelled one or a variable that
is no longer supported.
  warn('\n' + fill('Configuration variable "{0}" is defined in '
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/home/user/python/core/pywikibot/__init__.py", line 36, in <module>
    from pywikibot.data.api import UploadWarning
  File "/home/user/python/core/pywikibot/data/api.py", line 33, in <module>
    from pywikibot.comms import http
  File "/home/user/python/core/pywikibot/comms/http.py", line 68, in <module>
    debug('Loaded cookies from file.', _logger)
  File "/home/user/python/core/pywikibot/logging.py", line 182, in debug
    logoutput(text, decoder, newline, DEBUG, layer, **kwargs)
  File "/home/user/python/core/pywikibot/logging.py", line 78, in logoutput
    _init()
  File "/home/user/python/core/pywikibot/logging.py", line 34, in _init
    init_routine()
  File "/home/user/python/core/pywikibot/bot.py", line 344, in init_handlers
    writelogheader()
  File "/home/user/python/core/pywikibot/bot.py", line 405, in writelogheader
    filename = version.get_module_filename(module)
  File "/home/user/python/core/pywikibot/version.py", line 450, in get_module_filename
    if hasattr(module, '__file__') and os.path.exists(module.__file__):
  File "/home/user/anaconda3/lib/python3.8/genericpath.py", line 19, in exists
    os.stat(path)
TypeError: stat: path should be string, bytes, os.PathLike or integer, not NoneType
Xqt added a comment.Oct 3 2020, 5:58 AM

Works for me:

Python 3.8.5 (tags/v3.8.5:580fbb0, Jul 20 2020, 15:57:54) [MSC v.1924 64 bit (AMD64)] on win32
Type "help", "copyright", "credits" or "license()" for more information.
>>> import pywikibot

Warning (from warnings module):
  File "C:\pwb\GIT\core\pywikibot\config2.py", line 1066
    warn('\n' + fill('Configuration variable "{0}" is defined in '
UserWarning: 
Configuration variable "oauth_tokens" is defined in your user-
config.py but unknown. It can be a misspelled one or a variable that
is no longer supported.
>>>
2020-10-03 07:56:21             bot.py,  353 in     writelogheader: VERBOSE
2020-10-03 07:56:21             bot.py,  354 in     writelogheader: VERBOSE  === Pywikibot framework v5.0.0.dev0 -- Logging header ===
2020-10-03 07:56:21             bot.py,  358 in     writelogheader: VERBOSE  COMMAND: ['']
2020-10-03 07:56:21             bot.py,  361 in     writelogheader: VERBOSE  DATE: 2020-10-03 05:56:21.062194 UTC
2020-10-03 07:56:21             bot.py,  365 in     writelogheader: VERBOSE  VERSION: [ssh] pywikibot-core (0d1d224, g13245, 2020/10/02, 18:44:32, n/a)
2020-10-03 07:56:21             bot.py,  375 in     writelogheader: VERBOSE  CONFIG FILE DIR: C:\pwb\GIT\core
2020-10-03 07:56:21             bot.py,  391 in     writelogheader: VERBOSE  PACKAGES:
2020-10-03 07:56:21             bot.py,  398 in     writelogheader: VERBOSE    mwparserfromhell: No module named 'mwparserfromhell'
2020-10-03 07:56:21             bot.py,  400 in     writelogheader: VERBOSE    requests (C:\Python38\lib\site-packages\requests\) = 2.24.0
2020-10-03 07:56:21             bot.py,  403 in     writelogheader: VERBOSE  MODULES:
2020-10-03 07:56:21             bot.py,  409 in     writelogheader: VERBOSE    C:\pwb\GIT\core\pywikibot\__init__.py .dev 2020-10-02 17:39:37.802086
2020-10-03 07:56:21             bot.py,  409 in     writelogheader: VERBOSE    C:\pwb\GIT\core\pywikibot\__metadata__.py .dev 2020-10-02 17:39:37.802086
2020-10-03 07:56:21             bot.py,  409 in     writelogheader: VERBOSE    C:\pwb\GIT\core\pywikibot\comms\http.py .dev 2020-10-02 17:39:37.802086
2020-10-03 07:56:21             bot.py,  415 in     writelogheader: VERBOSE  =========================================================
gerritbot added a comment.Oct 3 2020, 7:03 AM

Change 631904 had a related patch set uploaded (by Xqt; owner: Xqt):
[pywikibot/core@master] [bugfix] fix version.get_module_filename()

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

gerritbot added a project: Patch-For-Review.Oct 3 2020, 7:03 AM
gerritbot added a comment.Oct 3 2020, 10:45 AM

Change 631904 merged by jenkins-bot:
[pywikibot/core@master] [bugfix] fix version.get_module_filename()

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

Xqt closed this task as Resolved.Oct 3 2020, 10:52 AM
Xqt mentioned this in rPWBC25fec5ecca16: [bugfix] fix version.get_module_filename().Oct 3 2020, 10:53 AM
Maintenance_bot removed a project: Patch-For-Review.Oct 3 2020, 11:10 AM
Mpaa reopened this task as Open.Oct 6 2020, 2:19 PM

Now I see it is printed twice.
e.g. see python pwb.py login -debug

Xqt added a comment.Oct 6 2020, 5:28 PM

strange: pwb prints one whereas pwb -help prints two headers

Xqt renamed this task from log header in log files is not written to log header in log files is written twice.Oct 7 2020, 6:13 AM
Mpaa added a comment.Oct 7 2020, 9:55 AM
(base)user@pc:~/python/core {master}$ python pwb.py

  File "/home/user/python/core/pywikibot/__init__.py", line 1311, in _flush
    debug('_flush() called', _logger)
  File "/home/user/python/core/pywikibot/logging.py", line 182, in debug
    logoutput(text, decoder, newline, DEBUG, layer, **kwargs)
  File "/home/user/python/core/pywikibot/logging.py", line 78, in logoutput
    _init()
  File "/home/user/python/core/pywikibot/logging.py", line 34, in _init
    init_routine()
  File "/home/user/python/core/pywikibot/bot.py", line 345, in init_handlers
    writelogheader()
  File "/home/user/python/core/pywikibot/bot.py", line 354, in writelogheader
    __import__('traceback').print_stack()

(base)user@pc:~/python/core {master}$ python pwb.py -help
  File "pwb.py", line 362, in <module>
    if not main():
  File "pwb.py", line 307, in main
    unknown_args = pwb.handle_args(global_args)
  File "/home/user/python/core/pywikibot/bot.py", line 851, in handle_args
    pywikibot.Site()
  File "/home/user/python/core/pywikibot/tools/__init__.py", line 1451, in wrapper
    return obj(*__args, **__kw)
  File "/home/user/python/core/pywikibot/__init__.py", line 1225, in Site
    debug("Instantiated %s object '%s'"
  File "/home/user/python/core/pywikibot/logging.py", line 182, in debug
    logoutput(text, decoder, newline, DEBUG, layer, **kwargs)
  File "/home/user/python/core/pywikibot/logging.py", line 78, in logoutput
    _init()
  File "/home/user/python/core/pywikibot/logging.py", line 34, in _init
    init_routine()
  File "/home/user/python/core/pywikibot/bot.py", line 345, in init_handlers
    writelogheader()
  File "/home/user/python/core/pywikibot/bot.py", line 354, in writelogheader
    __import__('traceback').print_stack()

  File "pwb.py", line 362, in <module>
    if not main():
  File "pwb.py", line 307, in main
    unknown_args = pwb.handle_args(global_args)
  File "/home/user/python/core/pywikibot/bot.py", line 859, in handle_args
    init_handlers()
  File "/home/user/python/core/pywikibot/bot.py", line 345, in init_handlers
    writelogheader()
  File "/home/user/python/core/pywikibot/bot.py", line 354, in writelogheader
    __import__('traceback').print_stack()
Xqt mentioned this in T281643: Pywikibot: avoid double logging of output.May 2 2021, 6:46 PM
gerritbot added a comment.Jul 6 2021, 11:44 AM

Change 703402 had a related patch set uploaded (by Xqt; author: Xqt):

[pywikibot/core@master] [bugfix] Rewrite init_handlers and RotatingFileHandler

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

gerritbot added a project: Patch-For-Review.Jul 6 2021, 11:44 AM
Xqt changed the subtype of this task from "Task" to "Bug Report".Jul 6 2021, 11:45 AM
Xqt added a subtask: T286348: userinterface is not properly set if bot.py has a ModuleDeprecationWrapper.Jul 8 2021, 3:37 PM
Xqt added a parent task: T286238: Add TimedRotatingFileHandler to core.Jul 8 2021, 3:40 PM
Xqt moved this task from Backlog to Logging on the Pywikibot board.Apr 25 2022, 7:52 AM
gerritbot added a comment.Apr 25 2022, 4:23 PM

Change 785882 had a related patch set uploaded (by Xqt; author: Xqt):

[pywikibot/core@master] [bugfix] Don not print log header twice in log files

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

gerritbot added a comment.Apr 26 2022, 1:44 PM

Change 703402 abandoned by Xqt:

[pywikibot/core@master] [bugfix] Rewrite init_handlers and RotatingFileHandler

Reason:

done wih other patches, T286127 isn't solved here, see task

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

Xqt removed a subtask: T286348: userinterface is not properly set if bot.py has a ModuleDeprecationWrapper.Apr 26 2022, 4:28 PM
Xqt removed a parent task: T286238: Add TimedRotatingFileHandler to core.
gerritbot added a comment.Apr 30 2022, 10:24 PM

Change 785882 merged by jenkins-bot:

[pywikibot/core@master] [bugfix] Do not print log header twice in log files

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

Xqt closed this task as Resolved.Apr 30 2022, 10:56 PM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits