Description of problem: ======================= On longevity setup consists of hot tier {6x2} and cold tier {2x (4 + 2)}. Stopping volume and starting back continuous logs below error in bricks: [2015-10-29 08:29:01.694498] E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB [2015-10-29 08:29:01.694545] E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert [2015-10-29 08:29:01.694562] E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed The message "E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB" repeated 4513 times between [2015-10-29 08:29:01.694498] and [2015-10-29 08:31:01.636651] The message "E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert" repeated 4513 times between [2015-10-29 08:29:01.694545] and [2015-10-29 08:31:01.636654] The message "E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed" repeated 4513 times between [2015-10-29 08:29:01.694562] and [2015-10-29 08:31:01.636655] [2015-10-29 08:31:01.699494] E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB [2015-10-29 08:31:01.699522] E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert [2015-10-29 08:31:01.699534] E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed The message "E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB" repeated 4377 times between [2015-10-29 08:31:01.699494] and [2015-10-29 08:33:01.636690] The message "E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert" repeated 4377 times between [2015-10-29 08:31:01.699522] and [2015-10-29 08:33:01.636692] The message "E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed" repeated 4377 times between [2015-10-29 08:31:01.699534] and [2015-10-29 08:33:01.636694] [2015-10-29 08:33:01.750465] E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB [2015-10-29 08:33:01.750501] E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert [2015-10-29 08:33:01.750510] E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed The message "E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB" repeated 3848 times between [2015-10-29 08:33:01.750465] and [2015-10-29 08:35:01.688212] The message "E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert" repeated 3848 times between [2015-10-29 08:33:01.750501] and [2015-10-29 08:35:01.688213] The message "E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed" repeated 3848 times between [2015-10-29 08:33:01.750510] and [2015-10-29 08:35:01.688214] [2015-10-29 08:35:01.845733] E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB [2015-10-29 08:35:01.845775] E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert [2015-10-29 08:35:01.845789] E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed The message "E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB" repeated 3954 times between [2015-10-29 08:35:01.845733] and [2015-10-29 08:37:01.532783] The message "E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert" repeated 3954 times between [2015-10-29 08:35:01.845775] and [2015-10-29 08:37:01.532786] The message "E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed" repeated 3954 times between [2015-10-29 08:35:01.845789] and [2015-10-29 08:37:01.532788] [2015-10-29 08:37:01.940133] E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB [2015-10-29 08:37:01.940187] E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert [2015-10-29 08:37:01.940203] E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed The message "E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB" repeated 3347 times between [2015-10-29 08:37:01.940133] and [2015-10-29 08:39:01.422669] The message "E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert" repeated 3347 times between [2015-10-29 08:37:01.940187] and [2015-10-29 08:39:01.422672] The message "E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed" repeated 3347 times between [2015-10-29 08:37:01.940203] and [2015-10-29 08:39:01.422674] [2015-10-29 08:39:01.798003] E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB [2015-10-29 08:39:01.798047] E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert [2015-10-29 08:39:01.798062] E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed The message "E [MSGID: 101027] [gfdb_sqlite3_helper.c:800:gf_sql_insert_wind] 0-sqlite3: Failed inserting link in DB" repeated 2903 times between [2015-10-29 08:39:01.798003] and [2015-10-29 08:41:01.750550] The message "E [MSGID: 101027] [gfdb_sqlite3.c:542:gf_sqlite3_insert] 0-sqlite3: Failed wind insert" repeated 2903 times between [2015-10-29 08:39:01.798047] and [2015-10-29 08:41:01.750552] The message "E [MSGID: 101130] [gfdb_data_store.c:387:insert_record] 0-gfdbdatastore: Insert/Update operation failed" repeated 2903 times between [2015-10-29 08:39:01.798062] and [2015-10-29 08:41:01.750553 [root@dhcp37-165 glusterfs]# grep "800:gf_sql_insert_wind" bricks/rhs-brick1-tiervolume_ct-disp1.log | wc -l 2515 [root@dhcp37-165 glusterfs]# Version-Release number of selected component (if applicable): ============================================================= glusterfs-3.7.5-0.3.el7rhgs.x86_64 Steps carried: ============== 1. 12 node cluster 2. Hot tier {6x2} , Cold tier {2x(4=2)} 3. Mounted the volume on 7.2,7.1 and 6.7 clients 4. Huge set of data is created on volume {148GB} 5. Stopped the volume {No data creation or IO was in progress at this time} 6. Started the volume
This is caused due to the lookup heal. Well CTR doesnt read from the DB, so to make sure that file records are created it does a heal during a lookup. It remembers the decision in the inode context cache and retrys periodically. When the volume is restarted it looses all the inode cache from the previous time and CTR lookup heals tries the heal again, but this time it finds that the records are already there from sql and logs this error, and remembers this until the volume is restarted or inode is flushed out of inode cache of the brick. Solution: the log levels should be reduced to trace for this case and customers need not see this.
What is the default? Default should be, we do not see the logs. If more information is needed, then we setup the loglevel to see the additional logs.
Well any insert/update failure to the Db should be ERROR. But for this special case we should use TRACE.
Upstream patch posted : http://review.gluster.org/#/c/12491
Per RCA, the log message is not an error. The merged patch makes the behavior visible at the trace level.
this has not been put up in 3.7.5-6 as it has been moved to modified from on_qa by dev
Verified with build: glusterfs-3.7.5-13.el7rhgs.x86_64 No errors related to insert/update is observed on brick logs. Moving the bug to verified state. [root@dhcp37-165 glusterfs]# grep -ri "insert" * [root@dhcp37-165 glusterfs]# [root@dhcp37-165 bricks]# grep -ri "insert" * [root@dhcp37-165 bricks]#
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHBA-2016-0193.html