Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Circular Reference Detected when serializing log record #286

Closed
swenzel opened this issue Jun 12, 2020 · 3 comments
Closed

Circular Reference Detected when serializing log record #286

swenzel opened this issue Jun 12, 2020 · 3 comments
Labels
bug Something isn't working

Comments

@swenzel
Copy link

swenzel commented Jun 12, 2020

When running the following python script:

import sys
from loguru import logger

config = {
    "handlers": [
        {"sink": sys.stdout, "format": "{time} - {message}", "serialize": True, "colorize": True},
    ],
}
logger.configure(**config)
with logger.catch():
    raise RuntimeError("Something happened")

I get:

--- Logging error in Loguru Handler #1 ---
Record was: {'elapsed': datetime.timedelta(microseconds=21630), 'exception': (type=<class 'RuntimeError'>, value=RuntimeError('Something happened'), traceback=<traceback object at 0x7f981875cbe0>), 'extra': {'record': {...}}, 'file': (name='test.py', path='test.py'), 'function': '<module>', 'level': (name='ERROR', no=40, icon='❌'), 'line': 11, 'message': "An error has been caught in function '<module>', process 'MainProcess' (80051), thread 'MainThread' (140291248607616):", 'module': 'test', 'name': '__main__', 'process': (id=80051, name='MainProcess'), 'thread': (id=140291248607616, name='MainThread'), 'time': datetime(2020, 6, 12, 12, 12, 51, 845339, tzinfo=datetime.timezone(datetime.timedelta(seconds=7200), 'CEST'))}
Traceback (most recent call last):
  File "test.py", line 11, in <module>
    raise RuntimeError("Something happened")
RuntimeError: Something happened

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/user/.local/share/virtualenvs/test-TSP576Db/lib/python3.7/site-packages/loguru/_handler.py", line 165, in emit
    formatted = self._serialize_record(formatted, record)
  File "/home/user/.local/share/virtualenvs/test-TSP576Db/lib/python3.7/site-packages/loguru/_handler.py", line 253, in _serialize_record
    return json.dumps(serializable, default=str) + "\n"
  File "/home/user/.asdf/installs/python/3.7.7/lib/python3.7/json/__init__.py", line 238, in dumps
    **kw).encode(obj)
  File "/home/user/.asdf/installs/python/3.7.7/lib/python3.7/json/encoder.py", line 199, in encode
    chunks = self.iterencode(o, _one_shot=True)
  File "/home/user/.asdf/installs/python/3.7.7/lib/python3.7/json/encoder.py", line 257, in iterencode
    return _iterencode(o, 0)
ValueError: Circular reference detected
--- End of logging error ---

I'm using loguru==0.5.0 and python==3.7.7.
Looks like the problem is that record["extra"] has an item "record" which points back to record so that record is record["extra"]["record"] which is used in the object that shall be serialized and causes a circular reference within _serialize_record here:

"extra": record["extra"],

@Delgan Delgan added the bug Something isn't working label Jun 12, 2020
@Delgan
Copy link
Owner

Delgan commented Jun 12, 2020

Thanks for the report!

It's a new bug in 0.5.0: while logging a message like logger.info("Log message", foobar=123) the **kwargs are now automatically added to the extra dict. However, when an error is captured and logged by catch(), the record is added to the **kwargs so that useful information can be displayed (e.g. "An unexpected error occurred in thread {record[thread]}"). The same problem would occur using logger.opt(record=True).info("It's a bug").

I'll fix it and publish a new version later today, thank you!

@swenzel
Copy link
Author

swenzel commented Jun 12, 2020

Thanks for the report!

You're welcome, this is the least I can do 🙂
Thanks for this awesome logging library, keep up the good work!

@Delgan
Copy link
Owner

Delgan commented Jun 12, 2020

Thanks for this awesome logging library, keep up the good work!

Thank you! 😃

I published v0.5.1, the error should be gone now. 👍

@Delgan Delgan closed this as completed Jun 12, 2020
jhamon pushed a commit to pinecone-io/pinecone-python-client that referenced this issue Oct 11, 2023
Bumps [loguru](https://github.com/Delgan/loguru) from 0.5.0 to 0.5.3.
<details>
<summary>Release notes</summary>
<p><em>Sourced from <a
href="https://github.com/Delgan/loguru/releases">loguru's
releases</a>.</em></p>
<blockquote>
<h2>0.5.3</h2>
<ul>
<li>Fix child process possibly hanging at exit while combining
<code>enqueue=True</code> with third party library like
<code>uwsgi</code> (<a
href="https://redirect.github.com/Delgan/loguru/issues/309">#309</a>,
thanks <a
href="https://github.com/dstlmrk"><code>@​dstlmrk</code></a>).</li>
<li>Fix possible exception during formatting of non-string messages (<a
href="https://redirect.github.com/Delgan/loguru/issues/331">#331</a>).</li>
</ul>
<h2>0.5.2</h2>
<ul>
<li>Fix <code>AttributeError</code> within handlers using
<code>serialize=True</code> when calling <code>logger.exception()</code>
outside of the context of an exception (<a
href="https://redirect.github.com/Delgan/loguru/issues/296">#296</a>).</li>
<li>Fix error while logging an exception containing a non-picklable
<code>value</code> to a handler with <code>enqueue=True</code> (<a
href="https://redirect.github.com/Delgan/loguru/issues/298">#298</a>).</li>
<li>Add support for async callable classes (with <code>__call__</code>
method) used as sinks (<a
href="https://redirect.github.com/Delgan/loguru/issues/294">#294</a>,
thanks <a
href="https://github.com/jessekrubin"><code>@​jessekrubin</code></a>).</li>
</ul>
<h2>0.5.1</h2>
<ul>
<li>Modify the way the <code>extra</code> dict is used by
<code>LogRecord</code> in order to prevent possible
<code>KeyError</code> with standard <code>logging</code> handlers (<a
href="https://redirect.github.com/Delgan/loguru/issues/271">#271</a>).</li>
<li>Add a new <code>default</code> optional argument to
<code>logger.catch()</code>, it should be the returned value by the
decorated function in case an error occurred (<a
href="https://redirect.github.com/Delgan/loguru/issues/272">#272</a>).</li>
<li>Fix <code>ValueError</code> when using <code>serialize=True</code>
in combination with <code>logger.catch()</code> or
<code>logger.opt(record=True)</code> due to circular reference of the
<code>record</code> dict (<a
href="https://redirect.github.com/Delgan/loguru/issues/286">#286</a>).</li>
</ul>
</blockquote>
</details>
<details>
<summary>Changelog</summary>
<p><em>Sourced from <a
href="https://github.com/Delgan/loguru/blob/master/CHANGELOG.rst">loguru's
changelog</a>.</em></p>
<blockquote>
<h1><code>0.5.3</code>_ (2020-09-20)</h1>
<ul>
<li>Fix child process possibly hanging at exit while combining
<code>enqueue=True</code> with third party library like
<code>uwsgi</code>
(<code>[#309](Delgan/loguru#309)
&lt;https://github.com/Delgan/loguru/issues/309&gt;</code><em>, thanks
<code>@dstlmrk &lt;https://github.com/dstlmrk&gt;</code></em>).</li>
<li>Fix possible exception during formatting of non-string messages
(<code>[#331](Delgan/loguru#331)
&lt;https://github.com/Delgan/loguru/issues/331&gt;</code>_).</li>
</ul>
<h1><code>0.5.2</code>_ (2020-09-06)</h1>
<ul>
<li>Fix <code>AttributeError</code> within handlers using
<code>serialize=True</code> when calling <code>logger.exception()</code>
outside of the context of an exception
(<code>[#296](Delgan/loguru#296)
&lt;https://github.com/Delgan/loguru/issues/296&gt;</code>_).</li>
<li>Fix error while logging an exception containing a non-picklable
<code>value</code> to a handler with <code>enqueue=True</code>
(<code>[#298](Delgan/loguru#298)
&lt;https://github.com/Delgan/loguru/issues/298&gt;</code>_).</li>
<li>Add support for async callable classes (with <code>__call__</code>
method) used as sinks
(<code>[#294](Delgan/loguru#294)
&lt;https://github.com/Delgan/loguru/pull/294&gt;</code><em>, thanks
<code>@jessekrubin
&lt;https://github.com/jessekrubin&gt;</code></em>).</li>
</ul>
<h1><code>0.5.1</code>_ (2020-06-12)</h1>
<ul>
<li>Modify the way the <code>extra</code> dict is used by
<code>LogRecord</code> in order to prevent possible
<code>KeyError</code> with standard <code>logging</code> handlers
(<code>[#271](Delgan/loguru#271)
&lt;https://github.com/Delgan/loguru/issues/271&gt;</code>_).</li>
<li>Add a new <code>default</code> optional argument to
<code>logger.catch()</code>, it should be the returned value by the
decorated function in case an error occurred
(<code>[#272](Delgan/loguru#272)
&lt;https://github.com/Delgan/loguru/issues/272&gt;</code>_).</li>
<li>Fix <code>ValueError</code> when using <code>serialize=True</code>
in combination with <code>logger.catch()</code> or
<code>logger.opt(record=True)</code> due to circular reference of the
<code>record</code> dict
(<code>[#286](Delgan/loguru#286)
&lt;https://github.com/Delgan/loguru/issues/286&gt;</code>_).</li>
</ul>
</blockquote>
</details>
<details>
<summary>Commits</summary>
<ul>
<li><a
href="https://github.com/Delgan/loguru/commit/f31e97142adc1156693a26ecaf47208d3765a6e3"><code>f31e971</code></a>
Bump version to 0.5.3</li>
<li><a
href="https://github.com/Delgan/loguru/commit/3394fdbd04efa7f5ec9c9625ec4ec34ca72b16e7"><code>3394fdb</code></a>
Update Changelog to reference <a
href="https://redirect.github.com/Delgan/loguru/issues/309">#309</a>
fix</li>
<li><a
href="https://github.com/Delgan/loguru/commit/44f677172ccf10ec60cbc46e4ac77394429211a7"><code>44f6771</code></a>
Fix removing simple queue in child processes (<a
href="https://redirect.github.com/Delgan/loguru/issues/325">#325</a>)</li>
<li><a
href="https://github.com/Delgan/loguru/commit/296635c33cbc735c3367728f24f07545dbfe19c5"><code>296635c</code></a>
Fix possible exception while formatting non-string message (<a
href="https://redirect.github.com/Delgan/loguru/issues/331">#331</a>)</li>
<li><a
href="https://github.com/Delgan/loguru/commit/b77f4fd23ac380fa2521dd2039c961af1218d1d1"><code>b77f4fd</code></a>
Correct simple typo in docs, propogates -&gt; propagates (<a
href="https://redirect.github.com/Delgan/loguru/issues/323">#323</a>)</li>
<li><a
href="https://github.com/Delgan/loguru/commit/e48f3e49228ada2f6495dd7eedc4ecd03530a1f6"><code>e48f3e4</code></a>
Bump version to 0.5.2</li>
<li><a
href="https://github.com/Delgan/loguru/commit/d93c19f6c1c53cc14e9afcb28b770f8aa43c28cd"><code>d93c19f</code></a>
Flesh out the few remaining incomplete annotations (<a
href="https://redirect.github.com/Delgan/loguru/issues/316">#316</a>)</li>
<li><a
href="https://github.com/Delgan/loguru/commit/084dffd16211e8494419ed5cf9c6859de8e76123"><code>084dffd</code></a>
Fix tests fails (since pytest upgrade) due to standard logging
misuse</li>
<li><a
href="https://github.com/Delgan/loguru/commit/9a40e58c74e786149b6a4c6097e24d50e0b40459"><code>9a40e58</code></a>
Fix error with &quot;enqueue=True&quot; and non-picklable exception (<a
href="https://redirect.github.com/Delgan/loguru/issues/298">#298</a>)</li>
<li><a
href="https://github.com/Delgan/loguru/commit/6f86f487590fe8f264a3bb26c722bf4be354687b"><code>6f86f48</code></a>
Refactor usage of &quot;inspect&quot; functions for simplification</li>
<li>Additional commits viewable in <a
href="https://github.com/Delgan/loguru/compare/0.5.0...0.5.3">compare
view</a></li>
</ul>
</details>
<br />


[![Dependabot compatibility
score](https://dependabot-badges.githubapp.com/badges/compatibility_score?dependency-name=loguru&package-manager=pip&previous-version=0.5.0&new-version=0.5.3)](https://docs.github.com/en/github/managing-security-vulnerabilities/about-dependabot-security-updates#about-compatibility-scores)

Dependabot will resolve any conflicts with this PR as long as you don't
alter it yourself. You can also trigger a rebase manually by commenting
`@dependabot rebase`.

[//]: # (dependabot-automerge-start)
[//]: # (dependabot-automerge-end)

---

<details>
<summary>Dependabot commands and options</summary>
<br />

You can trigger Dependabot actions by commenting on this PR:
- `@dependabot rebase` will rebase this PR
- `@dependabot recreate` will recreate this PR, overwriting any edits
that have been made to it
- `@dependabot merge` will merge this PR after your CI passes on it
- `@dependabot squash and merge` will squash and merge this PR after
your CI passes on it
- `@dependabot cancel merge` will cancel a previously requested merge
and block automerging
- `@dependabot reopen` will reopen this PR if it is closed
- `@dependabot close` will close this PR and stop Dependabot recreating
it. You can achieve the same result by closing it manually
- `@dependabot show <dependency name> ignore conditions` will show all
of the ignore conditions of the specified dependency
- `@dependabot ignore this major version` will close this PR and stop
Dependabot creating any more for this major version (unless you reopen
the PR or upgrade to it yourself)
- `@dependabot ignore this minor version` will close this PR and stop
Dependabot creating any more for this minor version (unless you reopen
the PR or upgrade to it yourself)
- `@dependabot ignore this dependency` will close this PR and stop
Dependabot creating any more for this dependency (unless you reopen the
PR or upgrade to it yourself)
You can disable automated security fix PRs for this repo from the
[Security Alerts
page](https://github.com/pinecone-io/pinecone-python-client/network/alerts).

</details>

Signed-off-by: dependabot[bot] <[email protected]>
Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants