Bug 1488707

Summary: tracker-extract crashes when processing virtual elements
Product: [Fedora] Fedora Reporter: Mikhail <mikhail.v.gavrilov>
Component: tracker-minersAssignee: Kalev Lember <klember>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: amigadave, dakingun, debarshir, ignatenko, klember, kparal, mikhail.v.gavrilov, robatino
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
URL: https://retrace.fedoraproject.org/faf/reports/bthash/ddd2120c6a1fb8b3756904968285085ab0b1383a
Whiteboard: abrt_hash:59e417ef1afa9de8d6dfb80a830974bc6860ef3e;VARIANT_ID=workstation; RejectedBlocker AcceptedFreezeException
Fixed In Version: tracker-miners-2.0.0-3.fc27 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-09-25 18:06:04 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1396702, 1396703    
Attachments:
Description Flags
File: backtrace
none
File: cgroup
none
File: core_backtrace
none
File: cpuinfo
none
File: dso_list
none
File: environ
none
File: exploitable
none
File: limits
none
File: maps
none
File: open_fds
none
File: proc_pid_status
none
File: var_log_messages
none
htop screenshot none

Description Mikhail 2017-09-06 03:22:01 UTC 
Description of problem:
Occured every second!!!!

Version-Release number of selected component:
tracker-1.99.0-1.fc27

Additional info:
reporter:       libreport-2.9.2
backtrace_rating: 4
cmdline:        /usr/libexec/tracker-extract
crash_function: g_str_hash
executable:     /usr/libexec/tracker-extract
journald_cursor: s=df6a9f8b489d427d9444424883d03d03;i=1ba14;b=87a3880f14db419aa5a2bfb37874b9ba;m=57941b8154;t=555ff7600134b;x=d0597f0541c6c65c
kernel:         4.13.0-0.rc2.git3.1.fc27.x86_64
rootdir:        /
runlevel:       N 5
type:           CCpp
uid:            1000

Truncated backtrace:
Thread no. 1 (7 frames)
 #0 g_str_hash at ghash.c:1882
 #1 g_hash_table_lookup_node at ghash.c:379
 #2 g_hash_table_lookup at ghash.c:1153
 #3 decorator_get_recovery_file at tracker-extract-decorator.c:228
 #4 decorator_next_item_cb at tracker-extract-decorator.c:277
 #5 g_task_return_now at gtask.c:1145
 #6 complete_in_idle_cb at gtask.c:1159

Potential duplicate: bug 1159895
Comment 1 Mikhail 2017-09-06 03:22:08 UTC 
Created attachment 1322474 [details]
File: backtrace
Comment 2 Mikhail 2017-09-06 03:22:10 UTC 
Created attachment 1322475 [details]
File: cgroup
Comment 3 Mikhail 2017-09-06 03:22:12 UTC 
Created attachment 1322476 [details]
File: core_backtrace
Comment 4 Mikhail 2017-09-06 03:22:13 UTC 
Created attachment 1322477 [details]
File: cpuinfo
Comment 5 Mikhail 2017-09-06 03:22:15 UTC 
Created attachment 1322478 [details]
File: dso_list
Comment 6 Mikhail 2017-09-06 03:22:16 UTC 
Created attachment 1322479 [details]
File: environ
Comment 7 Mikhail 2017-09-06 03:22:18 UTC 
Created attachment 1322480 [details]
File: exploitable
Comment 8 Mikhail 2017-09-06 03:22:19 UTC 
Created attachment 1322481 [details]
File: limits
Comment 9 Mikhail 2017-09-06 03:22:22 UTC 
Created attachment 1322482 [details]
File: maps
Comment 10 Mikhail 2017-09-06 03:22:23 UTC 
Created attachment 1322483 [details]
File: open_fds
Comment 11 Mikhail 2017-09-06 03:22:25 UTC 
Created attachment 1322484 [details]
File: proc_pid_status
Comment 12 Mikhail 2017-09-06 03:22:26 UTC 
Created attachment 1322485 [details]
File: var_log_messages
Comment 13 Mikhail 2017-09-08 03:30:25 UTC 
Similar problem has been detected:

Occured every second!!!!

reporter:       libreport-2.9.2
backtrace_rating: 4
cmdline:        /usr/libexec/tracker-extract
crash_function: g_str_hash
executable:     /usr/libexec/tracker-extract
journald_cursor: s=df6a9f8b489d427d9444424883d03d03;i=1ba14;b=87a3880f14db419aa5a2bfb37874b9ba;m=57941b8154;t=555ff7600134b;x=d0597f0541c6c65c
kernel:         4.13.0-0.rc2.git3.1.fc27.x86_64
package:        tracker-1.99.0-1.fc27
reason:         tracker-extract killed by signal 11
rootdir:        /
runlevel:       N 5
type:           CCpp
uid:            1000
Comment 14 Fedora Blocker Bugs Application 2017-09-09 06:55:17 UTC 
Proposed as a Blocker and Freeze Exception for 27-beta by Fedora user mikhail using the blocker tracking app because:

 Very annoying bug because happens every seconds.
Comment 15 Kamil Páral 2017-09-11 17:52:44 UTC 
Discussed during blocker review [1]:

RejectedBlocker (Beta) - for now, there is no indication this affects anyone besides Mikhail. We'd need information indicating this bug will hit a somewhat wider range of folks to accept it as a blocker

punt (delay decision) on FreezeException status - we don't have enough information on the cause, prevalence or fix for this yet to make an FE determination

[1] https://meetbot-raw.fedoraproject.org/fedora-blocker-review/2017-09-11/
Comment 16 Debarshi Ray 2017-09-17 00:08:24 UTC 
*** Bug 1478628 has been marked as a duplicate of this bug. ***
Comment 17 Kamil Páral 2017-09-18 17:59:01 UTC 
Discussed at blocker review meeting [1]:

AcceptedFreezeException - The fix seems to be small and shouldn't affect system much

[1] https://meetbot-raw.fedoraproject.org/fedora-blocker-review/2017-09-18
Comment 18 Fedora Update System 2017-09-19 09:42:49 UTC 
tracker-miners-2.0.0-3.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2017-2d2fb4e7d2
Comment 19 Fedora Update System 2017-09-19 23:29:36 UTC 
tracker-miners-2.0.0-3.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-2d2fb4e7d2
Comment 20 Mikhail 2017-09-24 14:21:18 UTC 
With latest tracker-miners package I don't see crashes, but now happens another problem:

Sep 24 19:08:29 localhost.localdomain systemd[3230]: Starting Tracker metadata database store and lookup manager...
Sep 24 19:08:29 localhost.localdomain systemd[3230]: Started Tracker metadata database store and lookup manager.
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Unable to insert multiple values for subject `http://www.tracker-project.org/temp/nmm#albumTitle' and single valued property `rdfs:comment' (old_value: 'nmm:albumTitle is deprecated, use nie:title instead, extractors still need updating', new value: 'nmm:albumTitle is deprecated, use nie:title instead')
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Could not insert FTS text: constraint failed
Sep 24 19:08:49 localhost.localdomain tracker-store[32589]: Transaction rollback failed: cannot rollback - no transaction is active
Sep 24 19:08:49 localhost.localdomain tracker-store[32589]: Cannot initialize database: constraint failed
Sep 24 19:08:49 localhost.localdomain systemd[3230]: tracker-store.service: Main process exited, code=exited, status=1/FAILURE
Sep 24 19:08:49 localhost.localdomain systemd[3230]: tracker-store.service: Unit entered failed state.
Sep 24 19:08:49 localhost.localdomain systemd[3230]: tracker-store.service: Failed with result 'exit-code'.
Sep 24 19:08:49 localhost.localdomain systemd[3230]: tracker-store.service: Service hold-off time over, scheduling restart.
Sep 24 19:08:49 localhost.localdomain systemd[3230]: Stopped Tracker metadata database store and lookup manager.
Sep 24 19:08:49 localhost.localdomain systemd[3230]: Starting Tracker metadata database store and lookup manager...
Sep 24 19:08:49 localhost.localdomain systemd[3230]: Started Tracker metadata database store and lookup manager.
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Unable to insert multiple values for subject `http://www.tracker-project.org/temp/nmm#albumTitle' and single valued property `rdfs:comment' (old_value: 'nmm:albumTitle is deprecated, use nie:title instead, extractors still need updating', new value: 'nmm:albumTitle is deprecated, use nie:title instead')
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:08 localhost.localdomain tracker-store[32659]: Could not insert FTS text: constraint failed
Sep 24 19:09:09 localhost.localdomain tracker-store[32659]: Transaction rollback failed: cannot rollback - no transaction is active
Sep 24 19:09:09 localhost.localdomain tracker-store[32659]: Cannot initialize database: constraint failed
Sep 24 19:09:09 localhost.localdomain systemd[3230]: tracker-store.service: Main process exited, code=exited, status=1/FAILURE
Sep 24 19:09:09 localhost.localdomain systemd[3230]: tracker-store.service: Unit entered failed state.
Sep 24 19:09:09 localhost.localdomain systemd[3230]: tracker-store.service: Failed with result 'exit-code'.
Sep 24 19:09:09 localhost.localdomain systemd[3230]: tracker-store.service: Service hold-off time over, scheduling restart.
Sep 24 19:09:09 localhost.localdomain systemd[3230]: Stopped Tracker metadata database store and lookup manager.


The whole log is full of these messages and tracker-store process continue consume 100% CPU
Comment 21 Mikhail 2017-09-24 14:22:06 UTC 
Created attachment 1330167 [details]
htop screenshot
Comment 22 Debarshi Ray 2017-09-24 16:20:59 UTC 
(In reply to Mikhail from comment #20)

Thanks for reporting back. These are different issues.

> Sep 24 19:08:29 localhost.localdomain systemd[3230]: Starting Tracker
> metadata database store and lookup manager...
> Sep 24 19:08:29 localhost.localdomain systemd[3230]: Started Tracker
> metadata database store and lookup manager.
> Sep 24 19:08:48 localhost.localdomain tracker-store[32589]: Unable to insert
> multiple values for subject
> `http://www.tracker-project.org/temp/nmm#albumTitle' and single valued
> property `rdfs:comment' (old_value: 'nmm:albumTitle is deprecated, use
> nie:title instead, extractors still need updating', new value:
> 'nmm:albumTitle is deprecated, use nie:title instead')

This bit is indicative of a bug in the miners that's worth filing upstream. Not sure about the rest of the logs.
Comment 23 Fedora Update System 2017-09-25 18:06:04 UTC 
tracker-miners-2.0.0-3.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report.