RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1342168 - Using libostree to pull several repositories stalls or crashes.
Summary: Using libostree to pull several repositories stalls or crashes.
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: ostree
Version: 7.3
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Colin Walters
QA Contact:
URL:
Whiteboard:
Depends On:
Blocks: 1329051
TreeView+ depends on / blocked
 
Reported: 2016-06-02 15:22 UTC by Jeff Ortel
Modified: 2020-12-15 07:41 UTC (History)
4 users (show)

Fixed In Version: ostree-2016.5-3.atomic.el7
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-12-15 07:41:52 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
Python reproducer that contains 2 files. (20.00 KB, application/x-tar)
2016-06-02 15:22 UTC, Jeff Ortel
no flags Details

Description Jeff Ortel 2016-06-02 15:22:27 UTC
Created attachment 1164103 [details]
Python reproducer that contains 2 files.

Description of problem:

Using libostree through python gobject to PULL several repositories results in:

1. Stalls - The progress continues to report the same values each second
   but PULL never progresses or completes.
2. Crashes. 


Version-Release number of selected component (if applicable):

ostree-2016.1-2 on RHEL6


How reproducible:

I have never seen the script complete.

Steps to Reproduce:
1. Extract the reproducer.
1. Edit the PATH and URL main.py to run as desired.
2. Run the reproducer:  $ python main.py

Actual results:

STALL:

{'status': None, 'requested': 15276L, 'bytes_transferred': 376660873L, 'fetched': 15194L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 376661334L, 'fetched': 15197L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 376661334L, 'fetched': 15197L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 376661334L, 'fetched': 15197L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 376661334L, 'fetched': 15197L, 'percent': 99}


================ OR ======================

CRASH:

*** Error in `python': double free or corruption (out): 0x00007fa978235000 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x7d053)[0x7fa9aaa2a053]
/lib64/libglib-2.0.so.0(g_free+0xf)[0x7fa9a2c9936f]
/lib64/libglib-2.0.so.0(+0x38258)[0x7fa9a2c82258]
/lib64/libglib-2.0.so.0(+0x3860e)[0x7fa9a2c8260e]
/lib64/libostree-1.so.1(+0x4ade3)[0x7fa9a0c40de3]
/lib64/libgio-2.0.so.0(+0x82a5d)[0x7fa9a254aa5d]
/lib64/libgobject-2.0.so.0(g_object_unref+0x1d4)[0x7fa9a2f95bc4]
/lib64/libglib-2.0.so.0(+0x46508)[0x7fa9a2c90508]
/lib64/libglib-2.0.so.0(+0x47bae)[0x7fa9a2c91bae]
/lib64/libglib-2.0.so.0(g_main_context_dispatch+0x1f0)[0x7fa9a2c93830]
/lib64/libglib-2.0.so.0(+0x49ae8)[0x7fa9a2c93ae8]
/lib64/libglib-2.0.so.0(g_main_context_iteration+0x2c)[0x7fa9a2c93b9c]
/lib64/libostree-1.so.1(ostree_repo_pull_with_options+0x1a13)[0x7fa9a0c46643]
/lib64/libostree-1.so.1(ostree_repo_pull_one_dir+0x122)[0x7fa9a0c472f2]
/lib64/libostree-1.so.1(ostree_repo_pull+0x22)[0x7fa9a0c47342]
/lib64/libffi.so.6(ffi_call_unix64+0x4c)[0x7fa9a2a47dac]
/lib64/libffi.so.6(ffi_call+0x1f5)[0x7fa9a2a476d5]
/usr/lib64/python2.7/site-packages/gi/_gi.so(+0x2c224)[0x7fa9a3632224]
/usr/lib64/python2.7/site-packages/gi/_gi.so(+0x2dba8)[0x7fa9a3633ba8]
/usr/lib64/python2.7/site-packages/gi/_gi.so(+0x2208e)[0x7fa9a362808e]
/lib64/libpython2.7.so.1.0(PyObject_Call+0x43)[0x7fa9ab6de0c3]
/lib64/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x1d4c)[0x7fa9ab77238c]
/lib64/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x7ed)[0x7fa9ab7761ed]
/lib64/libpython2.7.so.1.0(+0x6f1bd)[0x7fa9ab7031bd]
/lib64/libpython2.7.so.1.0(PyObject_Call+0x43)[0x7fa9ab6de0c3]
/lib64/libpython2.7.so.1.0(PyEval_EvalFrameEx+0xde7)[0x7fa9ab771427]
/lib64/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x7ed)[0x7fa9ab7761ed]
/lib64/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x425f)[0x7fa9ab77489f]
/lib64/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x4350)[0x7fa9ab774990]
/lib64/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x4350)[0x7fa9ab774990]
/lib64/libpython2.7.so.1.0(PyEval_EvalCodeEx+0x7ed)[0x7fa9ab7761ed]
/lib64/libpython2.7.so.1.0(PyEval_EvalCode+0x32)[0x7fa9ab7762f2]
/lib64/libpython2.7.so.1.0(+0xfb72f)[0x7fa9ab78f72f]
/lib64/libpython2.7.so.1.0(PyRun_FileExFlags+0x7e)[0x7fa9ab7908ee]
/lib64/libpython2.7.so.1.0(PyRun_SimpleFileExFlags+0xe9)[0x7fa9ab791b79]
/lib64/libpython2.7.so.1.0(Py_Main+0xc9f)[0x7fa9ab7a2caf]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7fa9aa9ceb15]
python[0x400721]
======= Memory map: ========
00400000-00401000 r-xp 00000000 fd:00 134375006                          /usr/bin/python2.7
00600000-00601000 r--p 00000000 fd:00 134375006                          /usr/bin/python2.7
00601000-00602000 rw-p 00001000 fd:00 134375006                          /usr/bin/python2.7
01920000-03cc9000 rw-p 00000000 00:00 0                                  [heap]
7fa964000000-7fa964022000 rw-p 00000000 00:00 0 
7fa964022000-7fa968000000 ---p 00000000 00:00 0 
7fa96c000000-7fa96c022000 rw-p 00000000 00:00 0 
7fa96c022000-7fa970000000 ---p 00000000 00:00 0 
7fa970000000-7fa970022000 rw-p 00000000 00:00 0 
7fa970022000-7fa974000000 ---p 00000000 00:00 0 
7fa974000000-7fa974022000 rw-p 00000000 00:00 0 
7fa974022000-7fa978000000 ---p 00000000 00:00 0 
7fa978000000-7fa97980c000 rw-p 00000000 00:00 0 
7fa97980c000-7fa97c000000 ---p 00000000 00:00 0 
7fa97dffc000-7fa97dffd000 ---p 00000000 00:00 0 
7fa97dffd000-7fa97e7fd000 rw-p 00000000 00:00 0                          [stack:8223]
7fa97effe000-7fa97efff000 ---p 00000000 00:00 0 
7fa97efff000-7fa97f7ff000 rw-p 00000000 00:00 0                          [stack:8227]
7fa97f7ff000-7fa97f800000 ---p 00000000 00:00 0 
7fa97f800000-7fa980000000 rw-p 00000000 00:00 0                          [stack:8220]
7fa980000000-7fa9817d7000 rw-p 00000000 00:00 0 
7fa9817d7000-7fa984000000 ---p 00000000 00:00 0 
7fa984000000-7fa985788000 rw-p 00000000 00:00 0 
7fa985788000-7fa988000000 ---p 00000000 00:00 0 
7fa988000000-7fa9899cc000 rw-p 00000000 00:00 0 
7fa9899cc000-7fa98c000000 ---p 00000000 00:00 0 
7fa98c000000-7fa98c027000 rw-p 00000000 00:00 0 
7fa98c027000-7fa990000000 ---p 00000000 00:00 0 
7fa990000000-7fa990026000 rw-p 00000000 00:00 0 
7fa990026000-7fa994000000 ---p 00000000 00:00 0 
7fa994d9d000-7fa994d9e000 ---p 00000000 00:00 0 
7fa994d9e000-7fa99559e000 rw-p 00000000 00:00 0                          [stack:8222]
7fa99559e000-7fa99559f000 ---p 00000000 00:00 0 
7fa99559f000-7fa995d9f000 rw-p 00000000 00:00 0                          [stack:8181]
7fa9965a0000-7fa9965a1000 ---p 00000000 00:00 0 
7fa9965a1000-7fa996da1000 rw-p 00000000 00:00 0                          [stack:8229]
7fa996da1000-7fa996da6000 r-xp 00000000 fd:00 202697935                  /usr/lib64/libnss_dns-2.17.so
7fa996da6000-7fa996fa5000 ---p 00005000 fd:00 202697935                  /usr/lib64/libnss_dns-2.17.so
7fa996fa5000-7fa996fa6000 r--p 00004000 fd:00 202697935                  /usr/lib64/libnss_dns-2.17.so
7fa996fa6000-7fa996fa7000 rw-p 00005000 fd:00 202697935                  /usr/lib64/libnss_dns-2.17.so
7fa996fa7000-7fa996fb3000 r-xp 00000000 fd:00 202697937                  /usr/lib64/libnss_files-2.17.so
7fa996fb3000-7fa9971b2000 ---p 0000c000 fd:00 202697937                  /usr/lib64/libnss_files-2.17.so
7fa9971b2000-7fa9971b3000 r--p 0000b000 fd:00 202697937                  /usr/lib64/libnss_files-2.17.so
7fa9971b3000-7fa9971b4000 rw-p 0000c000 fd:00 202697937                  /usr/lib64/libnss_files-2.17.so
7fa9971b4000-7fa9971ba000 rw-p 00000000 00:00 0 
7fa9971ba000-7fa9971bb000 ---p 00000000 00:00 0 
7fa9971bb000-7fa9979bb000 rw-p 00000000 00:00 0                          [stack:8228]
7fa9979bb000-7fa9979be000 r-xp 00000000 fd:00 201347476                  /usr/lib64/libkeyutils.so.1.5
7fa9979be000-7fa997bbd000 ---p 00003000 fd:00 201347476                  /usr/lib64/libkeyutils.so.1.5
7fa997bbd000-7fa997bbe000 r--p 00002000 fd:00 201347476                  /usr/lib64/libkeyutils.so.1.5
7fa997bbe000-7fa997bbf000 rw-p 00003000 fd:00 201347476                  /usr/lib64/libkeyutils.so.1.5
7fa997bbf000-7fa997bcc000 r-xp 00000000 fd:00 201886672                  /usr/lib64/libkrb5support.so.0.1
7fa997bcc000-7fa997dcc000 ---p 0000d000 fd:00 201886672                  /usr/lib64/libkrb5support.so.0.1
7fa997dcc000-7fa997dcd000 r--p 0000d000 fd:00 201886672                  /usr/lib64/libkrb5support.so.0.1
7fa997dcd000-7fa997dce000 rw-p 0000e000 fd:00 201886672                  /usr/lib64/libkrb5support.so.0.1
7fa997dce000-7fa997dfd000 r-xp 00000000 fd:00 201821343                  /usr/lib64/libk5crypto.so.3.1
7fa997dfd000-7fa997ffc000 ---p 0002f000 fd:00 201821343                  /usr/lib64/libk5crypto.so.3.1
7fa997ffc000-7fa997ffe000 r--p 0002e000 fd:00 201821343                  /usr/lib64/libk5crypto.so.3.1
7fa997ffe000-7fa997fff000 rw-p 00030000 fd:00 201821343                  /usr/lib64/libk5crypto.so.3.1Aborted

Expected results:


Additional info:

Comment 2 Colin Walters 2016-06-07 00:20:26 UTC
Does this reproduce at all for you on RHEL7 or newer?  Or is it specific to RHEL6?  It seems to be running okay here so far with ostree git master on a RHEL7-ish base.

Comment 3 Jeff Ortel 2016-06-09 20:07:36 UTC
Trying the reproducer on EL7 which also has ostree-2016.1-2.

Comment 4 Jeff Ortel 2016-06-10 14:47:44 UTC
Ran the reproducer on EL7 and it successfully completed all 100 pulls.  This strongly suggests this is only an issue on EL6.

Comment 5 Jeff Ortel 2016-06-10 14:57:35 UTC
Okay, sorry for the conflicting information but just got confirmation that the box where the reported crash happened was latest EL7.  I ran my test on 7.2.  Not sure where this leaves us.

Comment 6 Partha Aji 2016-06-14 18:05:43 UTC
We dont support ostree on RHEL 6 in satellite. Its only RHEL 7 at the present time because the RHEL 6 version of ostree doesnt do summary files. Customer produced it on RHEL 7.

Comment 7 Colin Walters 2016-06-14 20:09:29 UTC
Does the crash reproduce reliably for whoever reported it originally?

Comment 8 Jeff Ortel 2016-06-14 21:30:02 UTC
Not reliably.  The machine described here: https://bugzilla.redhat.com/show_bug.cgi?id=1329051#c14 is where the stack trace came from.  Both the crash and stalled pull have been observed when running the reproducer there.

Just ran the reproducer on that box.  The stalling:

{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 337469841L, 'fetched': 15140L, 'percent': 99}

seems easier to reproduce but I only observed the crash once.  The reproducer is in /root.  The PID=32922 but may not be running if you hop on the have a look.

Comment 9 Jeff Ortel 2016-06-15 20:09:49 UTC
Ran the reproducer with valgrind.  Here is the output.  

{'status': None, 'requested': 15276L, 'bytes_transferred': 376818097L, 'fetched': 15234L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 376839036L, 'fetched': 15266L, 'percent': 99}
{'status': None, 'requested': 15276L, 'bytes_transferred': 376850946L, 'fetched': 15274L, 'percent': 99}
--99590-- WARNING: unhandled syscall: 306
==99590==    at 0x5C0E687: syncfs (in /usr/lib64/libc-2.17.so)
==99590==    by 0x110FA430: ostree_repo_commit_transaction (in /usr/lib64/libostree-1.so.1.0.0)
==99590==    by 0x11121942: ostree_repo_pull_with_options (in /usr/lib64/libostree-1.so.1.0.0)
==99590==    by 0x111222F1: ostree_repo_pull_one_dir (in /usr/lib64/libostree-1.so.1.0.0)
==99590==    by 0x11122341: ostree_repo_pull (in /usr/lib64/libostree-1.so.1.0.0)
==99590==    by 0xE84ADAB: ffi_call_unix64 (in /usr/lib64/libffi.so.6.0.1)
==99590==    by 0xE84A6D4: ffi_call (in /usr/lib64/libffi.so.6.0.1)
==99590==    by 0xDC68223: ??? (in /usr/lib64/python2.7/site-packages/gi/_gi.so)
==99590==    by 0xDC69BA7: ??? (in /usr/lib64/python2.7/site-packages/gi/_gi.so)
==99590==    by 0xDC5E08D: ??? (in /usr/lib64/python2.7/site-packages/gi/_gi.so)
==99590==    by 0x4E7F0C2: PyObject_Call (in /usr/lib64/libpython2.7.so.1.0)
==99590==    by 0x4F1338B: PyEval_EvalFrameEx (in /usr/lib64/libpython2.7.so.1.0)
--99590-- You may be able to write your own handler.
--99590-- Read the file README_MISSING_SYSCALL_OR_IOCTL.
--99590-- Nevertheless we consider this a bug.  Please report
--99590-- it at http://valgrind.org/support/bug_reports.html.
Traceback (most recent call last):
  File "main.py", line 43, in <module>
    test()
  File "main.py", line 37, in test
    pull(path)
  File "main.py", line 29, in pull
    repository.pull(remote_id='test', refs=None, listener=show)
  File "/root/lib.py", line 30, in _fn
    raise LibError(repr(ge))
lib.LibError: GLib.Error('Function not implemented', 'g-io-error-quark', 0)
==99590== Warning: invalid file descriptor -1 in syscall close()
==99590==    at 0x520928D: ??? (in /usr/lib64/libpthread-2.17.so)
==99590==    by 0x11127B3D: ??? (in /usr/lib64/libostree-1.so.1.0.0)
==99590==    by 0x110EE322: ??? (in /usr/lib64/libostree-1.so.1.0.0)
==99590==    by 0xE2D2BC3: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.4200.2)
==99590==    by 0xDC54968: ??? (in /usr/lib64/python2.7/site-packages/gi/_gi.so)
==99590==    by 0x4ED12A2: ??? (in /usr/lib64/libpython2.7.so.1.0)
==99590==    by 0x4EB48FE: ??? (in /usr/lib64/libpython2.7.so.1.0)
==99590==    by 0x4ED1343: ??? (in /usr/lib64/libpython2.7.so.1.0)
==99590==    by 0x4EB48FE: ??? (in /usr/lib64/libpython2.7.so.1.0)
==99590==    by 0x4ED1343: ??? (in /usr/lib64/libpython2.7.so.1.0)
==99590==    by 0x4EA2AF1: ??? (in /usr/lib64/libpython2.7.so.1.0)
==99590==    by 0x4F3A05A: ??? (in /usr/lib64/libpython2.7.so.1.0)
--99590-- Discarding syms at 0x17c37240-0x17c3e454 in /usr/lib64/libnss_files-2.17.so due to munmap()
--99590-- Discarding syms at 0x17e49100-0x17e4c590 in /usr/lib64/libnss_dns-2.17.so due to munmap()
==99590== 
==99590== HEAP SUMMARY:
==99590==     in use at exit: 7,171,783 bytes in 94,557 blocks
==99590==   total heap usage: 12,195,532 allocs, 12,100,975 frees, 3,492,934,472 bytes allocated
==99590== 
==99590== Searching for pointers to 94,396 not-freed blocks
==99590== Checked 22,747,424 bytes
==99590== 
==99590== LEAK SUMMARY:
==99590==    definitely lost: 1,428,715 bytes in 30,551 blocks
==99590==    indirectly lost: 2,113,617 bytes in 41,449 blocks
==99590==      possibly lost: 1,118,026 bytes in 3,837 blocks
==99590==    still reachable: 2,489,457 bytes in 18,559 blocks
==99590==         suppressed: 0 bytes in 0 blocks
==99590== Rerun with --leak-check=full to see details of leaked memory
==99590== 
==99590== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 1 from 1)
--99590-- 
--99590-- used_suppression:      1 glibc-2.5.x-on-SUSE-10.2-(PPC)-2a /usr/lib64/valgrind/default.supp:1296
==99590== 
==99590== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 1 from 1)

Comment 10 Colin Walters 2016-06-15 20:21:04 UTC
Okay so that's worked around in git master https://github.com/ostreedev/ostree/pull/292

It's a bug in valgrind on EL7, so we're not getting any useful information.

Alternatively I could look at building a newer valgrind.

Yet another alternative is to try the ostree binaries from CAHC:
https://wiki.centos.org/SpecialInterestGroup/Atomic/Devel

Comment 11 Jeff Ortel 2016-06-15 21:41:56 UTC
Installed ostree-2016.5-2.atomic.el7.x86_64 (buildID=497039) and observed the stalled pull when running the reproducer:

{'status': None, 'requested': 15276L, 'bytes_transferred': 223357693L, 'fetched': 12617L, 'percent': 82}
{'status': None, 'requested': 15276L, 'bytes_transferred': 223357693L, 'fetched': 12617L, 'percent': 82}
{'status': None, 'requested': 15276L, 'bytes_transferred': 223357693L, 'fetched': 12617L, 'percent': 82}

Comment 12 Jeff Ortel 2016-06-15 21:45:07 UTC
I don't think we're going to get anywhere until someone from the Atomic team can ssh onto the affected box and investigate.

Comment 13 Colin Walters 2016-06-17 13:19:49 UTC
Sorry about this, it was easy to reproduce locally.  Working on it now.

https://github.com/ostreedev/ostree/pull/350

Comment 18 Jeff Ortel 2016-06-28 21:07:51 UTC
Saw this on RHEL 7.2 satellite box with RPM recommended on #17.  Scary warnings and critical log entries followed by the process SIGSEGV.  Trying with the ostree CLI next.

Packages:

ostree-2016.5-3.atomic.el7.x86_64
gobject-introspection-1.42.0-1.el7.x86_64
pygobject3-3.14.0-3.el7.x86_64
pygobject3-base-3.14.0-3.el7.x86_64
pygobject2-2.28.6-11.el7.x86_64
cairo-gobject-1.14.2-1.el7.x86_64
glibc-headers-2.17-106.el7_2.6.x86_64
glib-networking-2.42.0-1.el7.x86_64
glibc-devel-2.17-106.el7_2.6.x86_64
glibc-common-2.17-106.el7_2.6.x86_64
glibc-debuginfo-2.17-106.el7_2.6.x86_64
dbus-glib-0.100-7.el7.x86_64
glibc-2.17-106.el7_2.6.x86_64
glib2-2.42.2-5.el7.x86_64
json-glib-1.0.2-1.el7.x86_64
glibc-debuginfo-common-2.17-106.el7_2.6.x86_64

Log snip:


Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808) /usr/lib/python2.7/site-packages/pulp_ostree/plugins/lib.py:406: Warning: GError set over the top of a previous GError or uninitialized memory.
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808) This indicates a bug in someone's code. You must ensure an error is NULL before it's set.
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808) The overwriting error message was: Server returned status 403: Forbidden
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808)   self.impl.pull(self.id, refs, flags, None, None)
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808)
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808) /usr/lib/python2.7/site-packages/pulp_ostree/plugins/lib.py:406: Warning: g_object_ref: assertion 'G_IS_OBJECT (object)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808)   self.impl.pull(self.id, refs, flags, None, None)
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808)
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808) /usr/lib/python2.7/site-packages/pulp_ostree/plugins/lib.py:406: Warning: g_object_unref: assertion 'G_IS_OBJECT (object)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808)   self.impl.pull(self.id, refs, flags, None, None)
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: py.warnings:WARNING: (557-91808)
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_new: assertion '!source_object || G_IS_OBJECT (source_object)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_set_op_res_gpointer: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_run_in_thread: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_new: assertion '!source_object || G_IS_OBJECT (source_object)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_set_op_res_gpointer: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_run_in_thread: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_new: assertion '!source_object || G_IS_OBJECT (source_object)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_set_op_res_gpointer: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_run_in_thread: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_new: assertion '!source_object || G_IS_OBJECT (source_object)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_set_op_res_gpointer: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_run_in_thread: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_new: assertion '!source_object || G_IS_OBJECT (source_object)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_set_op_res_gpointer: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_run_in_thread: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_new: assertion '!source_object || G_IS_OBJECT (source_object)' failed
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 celery: (process:557): GLib-GIO-CRITICAL **: g_simple_async_result_set_op_res_gpointer: assertion 'G_IS_SIMPLE_ASYNC_RESULT (simple)' failed

...
GLib-GIO-CRITICAL  logged 1181 times.
...

Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: celery.worker.job:ERROR: (32700-91808) Task pulp.server.managers.repo.sync.sync[252ad894-d037-4bdb-bcd6-cc1b623fcc5e] raised unexpected: WorkerLostError('Worker exited prematurely: signal 11 (SIGSEGV).',)
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: celery.worker.job:ERROR: (32700-91808) Traceback (most recent call last):
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: celery.worker.job:ERROR: (32700-91808)   File "/usr/lib64/python2.7/site-packages/billiard/pool.py", line 1169, in mark_as_worker_lost
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: celery.worker.job:ERROR: (32700-91808)     human_status(exitcode)),
Jun 28 10:42:01 hp-dl380pgen8-02-vm-9 pulp: celery.worker.job:ERROR: (32700-91808) WorkerLostError: Worker exited prematurely: signal 11 (SIGSEGV).

Comment 19 Jeff Ortel 2016-06-29 18:23:14 UTC
Looks like this happened while pulling commits referenced in the summary file.  See pulp code here: https://github.com/pulp/pulp_ostree/blob/master/plugins/pulp_ostree/plugins/lib.py#L406 referenced in the trace and attached core file.

Let me know if a separate BZ would be more appropriate.

(gdb) bt
#0  __GI___libc_free (mem=0x1) at malloc.c:2931
#1  0x00007ff43902936f in g_free () from /lib64/libglib-2.0.so.0
#2  0x00007ff4331d4791 in ostree_repo_pull_with_options () from /lib64/libostree-1.so.1
#3  0x00007ff4331d8242 in ostree_repo_pull_one_dir () from /lib64/libostree-1.so.1
#4  0x00007ff4331d8292 in ostree_repo_pull () from /lib64/libostree-1.so.1
#5  0x00007ff44b905dac in ffi_call_unix64 () from /lib64/libffi.so.6
#6  0x00007ff44b9056d5 in ffi_call () from /lib64/libffi.so.6
#7  0x00007ff438128224 in pygi_invoke_c_callable () from /usr/lib64/python2.7/site-packages/gi/_gi.so
#8  0x00007ff438129ba8 in pygi_function_cache_invoke () from /usr/lib64/python2.7/site-packages/gi/_gi.so
#9  0x00007ff43811e08e in _callable_info_call () from /usr/lib64/python2.7/site-packages/gi/_gi.so
#10 0x00007ff454d5b0c3 in PyObject_Call (func=func@entry=<gi.FunctionInfo at remote 0x65919d0>, 
    arg=arg@entry=(u'Default_Organization-Red_Hat_Enterprise_Linux_Atomic_Host-Red_Hat_Enterprise_Linux_Atomic_Host_Trees', ['rhel-atomic-host/7/x86_64/standard'], <PyOSTreeRepoPullFlags at remote 0x50a7c00>, None, None), kw=kw@entry=0x0) at /usr/src/debug/Python-2.7.5/Objects/abstract.c:2529
#11 0x00007ff454def38c in do_call (nk=<optimized out>, na=5, pp_stack=0x7fffc9d4a660, func=<gi.FunctionInfo at remote 0x65919d0>)
    at /usr/src/debug/Python-2.7.5/Python/ceval.c:4316
#12 call_function (oparg=<optimized out>, pp_stack=0x7fffc9d4a660) at /usr/src/debug/Python-2.7.5/Python/ceval.c:4121
#13 PyEval_EvalFrameEx (
    f=f@entry=Frame 0x5114240, for file /usr/lib/python2.7/site-packages/pulp_ostree/plugins/lib.py, line 406, in list_refs (self=<Remote(gpg_validation=False, ssl_ca_path=None, repository=<Repository(path='/var/lib/pulp/content/shared/ostree/f3769796a028aff68cf0e680a3e84bd236833ad48c2700f1e593ea584e5e6abf/content', impl=<Repo at remote 0x51a3be0>) at remote 0x6593990>, url='', ssl_validation=False, proxy_url=None, ssl_key_path=None, id=u'Default_Organization-Red_Hat_Enterprise_Linux_Atomic_Host-Red_Hat_Enterprise_Linux_Atomic_Host_Trees', ssl_cert_path=None) at remote 0x6593fd0>, required=False, _list=[], lib=<Lib(GLib=<DynamicModule(_overrides_module=<module at remote 0x503fe50>, _namespace='GLib', _introspection_module=<IntrospectionModule(MAXINT8=127, source_remove=<gi.FunctionInfo at remote 0x5064e68>, _namespace='GLib', MININT32=-2147483648, IOFlags=<type at remote 0x507b740>, __path__='/usr/lib64/girepository-1.0/GLib-2.0.typelib', uri_list_extract_uris=<gi.FunctionInfo at remote 0x5064b58>, MAXINT16=32767, unix_sig...(truncated), 
    throwflag=throwflag@entry=0) at /usr/src/debug/Python-2.7.5/Python/ceval.c:2740

Comment 20 Jeff Ortel 2016-06-29 19:16:24 UTC
This produces reliably after 10-20 runs.  In this particular case, fetching the summary results in http-403 many times than it appears to magically succeed followed by the SIGSEGV.

Comment 22 Matthew Barnes 2016-07-07 17:45:53 UTC
FWIW, using the package list in comment #18 I managed to load Jeff's core file with a little more debuginfo, especially for ostree + glib.

If the line number in frame 4 is to be believed (and the other ostree frames *are* accurate), it's apparently crashing while trying to free the "metalink_url_str" string.  But I don't see how, unless this is memory corruption.

Thread 16 (Thread 0x7ff4552e4740 (LWP 19884)):
#0  0x00007ff4540aa63c in free () at /lib64/libc.so.6
#1  0x00007ff43902936f in g_malloc0 (n_bytes=1) at gmem.c:136
#2  0x00007fffc9d49f30 in  ()
#3  0x00007ff4331d4791 in ostree_repo_pull_with_options (p=0x7fffc9d49e90)
    at /usr/include/glib-2.0/glib/glib-autocleanups.h:28
#4  0x00007ff4331d4791 in ostree_repo_pull_with_options (self=self@entry=0x7ff418b3baf0, remote_name_or_baseurl=remote_name_or_baseurl@entry=0x64b14a0 "Default_Organization-Red_Hat_Enterprise_Linux_Atomic_Host-Red_Hat_Enterprise_Linux_Atomic_Host_Trees", options=<optimized out>, progress=progress@entry=0x0, cancellable=cancellable@entry=0x0, error=error@entry=0x7fffc9d4a490)
    at src/libostree/ostree-repo-pull.c:1894
#5  0x00007ff4331d8242 in ostree_repo_pull_one_dir (self=0x7ff418b3baf0, remote_name=0x64b14a0 "Default_Organization-Red_Hat_Enterprise_Linux_Atomic_Host-Red_Hat_Enterprise_Linux_Atomic_Host_Trees", dir_to_pull=dir_to_pull@entry=0x0, refs_to_fetch=0x7322180, flags=
    OSTREE_REPO_PULL_FLAGS_COMMIT_ONLY, progress=0x0, cancellable=0x0, error=error@entry=0x7fffc9d4a490) at src/libostree/ostree-repo-pull.c:1773
#6  0x00007ff4331d8292 in ostree_repo_pull (self=<optimized out>, remote_name=<optimized out>, refs_to_fetch=<optimized out>, flags=<optimized out>, progress=<optimized out>, cancellable=<optimized out>, error=0x7fffc9d4a490)
    at src/libostree/ostree-repo-pull.c:1747
#7  0x00007ff44b905dac in ffi_call_unix64 () at ../src/x86/unix64.S:64
#8  0x00007ff44b9056d5 in ffi_call (cif=<optimized out>, fn=<optimized out>, rvalue=0x7fffc9d4a3e0, avalue=0x63f1f40) at ../src/x86/ffi64.c:522
#9  0x00007ff438128224 in pygi_invoke_c_callable ()
    at /usr/lib64/python2.7/site-packages/gi/_gi.so
#10 0x00007ff438129ba8 in pygi_function_cache_invoke ()
    at /usr/lib64/python2.7/site-packages/gi/_gi.so
#11 0x00007ff43811e08e in _callable_info_call ()
    at /usr/lib64/python2.7/site-packages/gi/_gi.so
#12 0x00007ff454d5b0c3 in fastsearch (s=0x1 <Address 0x1 out of bounds>, n=5, p=0x0, m=17, maxcount=83535120, mode=96)
    at /usr/src/debug/Python-2.7.5/Objects/stringlib/fastsearch.h:51
#13 0x0000000000000000 in  ()

Comment 24 Jeff Ortel 2016-07-18 19:43:24 UTC
Trying.  The reproducer box was not mine and no longer exists.  I'm trying to reproduce the issue on another Satellite using ostree-2016.5-3.  So far, no luck.

Comment 25 Colin Walters 2016-07-18 21:10:11 UTC
@jortel can you be sure to use 2016.7 (at least).  See e.g. https://brewweb.engineering.redhat.com/brew/buildinfo?buildID=502788

Comment 26 Jeff Ortel 2016-07-18 22:22:24 UTC
I will but I wanted to reproduce the crash using an older version first.  Then, upgrade to 2016.7 to verify that it no longer crashes.

Comment 27 Jeff Ortel 2016-07-19 15:41:50 UTC
I'm not able to reproduce the crash using ostree 2016.5.3 or 2016.7.  Recommend we "move on" with the expectation this is fixed.

Comment 29 RHEL Program Management 2020-12-15 07:41:52 UTC
After evaluating this issue, there are no plans to address it further or fix it in an upcoming release.  Therefore, it is being closed.  If plans change such that this issue will be fixed in an upcoming release, then the bug can be reopened.


Note You need to log in before you can comment on or make changes to this bug.