| Bug #106280 | innodb print tons of partial read in error log | ||
|---|---|---|---|
| Submitted: | 25 Jan 2022 14:14 | Modified: | 28 Feb 2022 14:00 |
| Reporter: | WANG GUANGYOU | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S3 (Non-critical) |
| Version: | 5.7 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[25 Jan 2022 14:53]
MySQL Verification Team
Hi Mr. GUANGYOU, Thank you for your bug report. However, we can not proceed in processing your report, without additional info. First of all, we need a. fully reproducible test case. We need a test case that we would be able to repeat and got tons of messages in the error log. Next, we got lots of requests for adding info to the error log and not the other way around. Also, if you read our Manual, you can see that you can set verbosity of the error log. But, most important of all, we need a fully repeatable test case. Otherwise, this report will not be further processed.
[27 Jan 2022 2:29]
huahua xu
Hi Mr. GUANGYOU, You be right! It may be a bug. I find that the function my_pread overwrites the errno to 0 before it calls pread.
[26 Feb 2022 1:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
[28 Feb 2022 14:00]
MySQL Verification Team
Can't repeat without a test case and other infor.
[5 Sep 2022 10:36]
peng gao
Hi Mr. GUANGYOU,
I think this is a bug, I have the same problem , pread && blocking regular file read 0 bytes not set errno,means EOF。
{the number of bytes read is returned (zero indicates end of file)}
so errno not overwrite ,if last errno is EAGAIN ,so loop for ever.
[19 Sep 2022 11:01]
MySQL Verification Team
Hi, We wrote before and we will repeat the same statement. That is , we can not process a bug report without a fully reproducible test case.
[10 May 2:47]
alex xing
I ran into a similar bug in MySQL5.7 mysql crash when update/insert 2023-05-10T07:51:15.447690+08:00 2397544 [Warning] InnoDB: Retry attempts for reading partial data failed. 2023-05-10T07:51:15.455348+08:00 2397544 [ERROR] InnoDB: Tried to read 16384 bytes at offset 890486784, but was only able to read 0 2023-05-10T07:51:15.455372+08:00 2397544 [ERROR] InnoDB: Operating system error number 61 in a file operation. 2023-05-10T07:51:15.455395+08:00 2397544 [ERROR] InnoDB: Error number 61 means 'No data available' 2023-05-10T07:51:15.455959+08:00 2397544 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html 2023-05-10T07:51:15.455971+08:00 2397544 [ERROR] InnoDB: File (unknown): 'read' returned OS error 161. Cannot continue operation 2023-05-10T07:51:15.455977+08:00 2397544 [ERROR] InnoDB: Cannot continue operation. 2023-05-10T07:51:19.861129+08:00 0 [Note] InnoDB: FTS optimize thread exiting. 2023-05-10T07:52:55.535093+08:00 2397544 [Warning] InnoDB: 3 threads created by InnoDB had not exited at shutdown! 2023-05-09T23:53:01.994835Z 0 [Warning] The syntax 'expire-logs-days' is deprecated and will be removed in a future release. Please use binlog_expire_logs_seconds instead.
[10 May 12:01]
MySQL Verification Team
Hi, Version 5.7 now receives only fixes for the crashes and security problems. So, this report would qualify if we could had a repeatable test case. We still have not got one !!!!!
Description: I check the innodb code in os_file_read_page. I find a bug that the function may looped forever and print tons of error log under some situation. For example, if n_bytes != n and exit_on_error is ture and the last errno is EAGAIN , it will loop for ever. For the pread in os_file_pread will not overwrite the errno status if it read less bytes even zero byte . and will print line below repeatly ############################# 2022-01-20T11:44:27.405389+08:00 1988955 [Warning] InnoDB: 16384 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes. 2022-01-20T11:44:27.405404+08:00 1988955 [Warning] InnoDB: 16384 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes. 2022-01-20T11:44:27.405410+08:00 1988955 [Warning] InnoDB: 16384 bytes should have been read. Only 0 bytes read. Retrying for the remaining bytes. 2022-01-20T11:44:27.405414+08:00 1988955 [Warning] InnoDB: Retry attempts for reading partial data failed. 2022-01-20T11:44:27.405421+08:00 1988955 [ERROR] InnoDB: Tried to read 16384 bytes at offset 49152, but was only able to read 0 of FD 2987, filename /opt/local/mysql/var/__recyclebin__/__innodb_5586.ibd 2022-01-20T11:44:27.405427+08:00 1988955 [ERROR] InnoDB: Operating system error number 11 in a file operation. 2022-01-20T11:44:27.405432+08:00 1988955 [ERROR] InnoDB: Error number 11 means 'Resource temporarily unavailable' ############################# 6187 /** Requests a synchronous positioned read operation. 6188 @return DB_SUCCESS if request was successful, false if fail 6189 @param[in] type IO flags 6190 @param[in] file handle to an open file 6191 @param[out] buf buffer where to read 6192 @param[in] offset file offset from the start where to read 6193 @param[in] n number of bytes to read, starting from offset 6194 @param[out] o number of bytes actually read 6195 @param[in] exit_on_err if true then exit on error 6196 @return DB_SUCCESS or error code */ 6197 static MY_ATTRIBUTE((warn_unused_result)) 6198 dberr_t 6199 os_file_read_page( 6200 IORequest& type, 6201 os_file_t file, 6202 void* buf, 6203 os_offset_t offset, 6204 ulint n, 6205 ulint* o, 6206 bool exit_on_err, 6207 trx_t* trx) 6208 { 6209 dberr_t err; 6210 6211 os_bytes_read_since_printout += n; 6212 6213 ut_ad(type.validate()); 6214 ut_ad(n > 0); 6215 6216 for (;;) { 6217 ssize_t n_bytes; 6218 6219 n_bytes = os_file_pread(type, file, buf, n, offset, trx, &err); 6220 6221 if (o != NULL) { 6222 *o = n_bytes; 6223 } 6224 6225 if (err != DB_SUCCESS && !exit_on_err) { 6226 6227 return(err); 6228 6229 } else if ((ulint) n_bytes == n) { 6230 6231 /*The page decryption failed - will handled by buf_io_comptelete*/ 6232 if (err == DB_IO_DECRYPT_FAIL) 6233 return (DB_IO_DECRYPT_FAIL); 6234 6235 /** The read will succeed but decompress can fail 6236 for various reasons. */ 6237 6238 if (type.is_compression_enabled() 6239 && !Compression::is_compressed_page( 6240 static_cast<byte*>(buf))) { 6241 6242 return(DB_SUCCESS); 6243 6244 } else { 6245 return(err); 6246 } 6247 } 6248 6249 const std::string fd_path = os_file_find_path_for_fd(file); 6250 if (!fd_path.empty()) { 6251 ib::error() << "Tried to read " << n 6252 << " bytes at offset " << offset 6253 << ", but was only able to read " << n_bytes 6254 << " of FD " << file 6255 << ", filename " << fd_path; 6256 } else { 6257 ib::error() << "Tried to read " << n 6258 << " bytes at offset " << offset 6259 << ", but was only able to read " << n_bytes; 6260 } 6261 6262 if (exit_on_err) { 6263 ################################################################ if n_bytes != n and exit_on_error is ture and the last errno is EAGAIN , it will loop for ever. For the pread in os_file_pread will not overwrite the errno status if it read less bytes even zero byte ################################################################ 6264 if (!os_file_handle_error(NULL, "read")) { 6265 /* Hard error */ 6266 break; 6267 } 6268 6269 } else if (!os_file_handle_error_no_exit(NULL, "read", false)) { 6270 6271 /* Hard error */ 6272 break; 6273 } 6274 6275 if (n_bytes > 0 && (ulint) n_bytes < n) { 6276 n -= (ulint) n_bytes; 6277 offset += (ulint) n_bytes; 6278 buf = reinterpret_cast<uchar*>(buf) + (ulint) n_bytes; 6279 } 6280 } 6281 6282 ib::fatal() 6283 << "Cannot read from file. OS error number " 6284 << errno << "."; 6285 6286 return(err); 6287 } How to repeat: check the code Suggested fix: I have two suggestion: 1,supress the error log. It prints two much 2,the errno is thread local. Before read, we should overwrite the errno to 0. Or it will spread all over the code . And it is not right to use the errno.