Re: Log message --> "bdev(/var/lib/ceph/osd/ceph-x/block) aio_submit retries"

nokia ceph <nokiacephusers@xxxxxxxxx> · Wed, 15 Mar 2017 12:55:09 +0530

Hello,
We suspect these messages not only at the time of OSD creation. But in idle conditions also. May I know what is the impact of these error? Can we safely ignore this? Or is there any way/config to fix this problem

Few occurrence for these events as follows:--- 

====
2017-03-14 17:16:09.500370 7fedeba61700  4 rocksdb: (Original Log Time 2017/03/14-17:16:09.453130) [default] Level-0 commit table #60 started
2017-03-14 17:16:09.500374 7fedeba61700  4 rocksdb: (Original Log Time 2017/03/14-17:16:09.500273) [default] Level-0 commit table #60: memtable #1 done
2017-03-14 17:16:09.500376 7fedeba61700  4 rocksdb: (Original Log Time 2017/03/14-17:16:09.500297) EVENT_LOG_v1 {"time_micros": 1489511769500289, "job": 17, "event": "flush_finished", "lsm_state": [2, 4, 6, 0, 0, 0, 0], "immutable_memtables": 0}
2017-03-14 17:16:09.500382 7fedeba61700  4 rocksdb: (Original Log Time 2017/03/14-17:16:09.500330) [default] Level summary: base level 1 max bytes base 268435456 files[2 4 6 0 0 0 0] max score 0.76

2017-03-14 17:16:09.500390 7fedeba61700  4 rocksdb: [JOB 17] Try to delete WAL files size 244090350, prev total WAL file size 247331500, number of live WAL files 2.

2017-03-14 17:34:11.610513 7fedf3a71700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 6
2017-03-14 17:34:11.672123 7fedf226e700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 6
2017-03-14 17:34:11.696253 7fedf2a6f700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 10
2017-03-14 17:34:11.739016 7fedf3a71700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 10
2017-03-14 17:51:08.808848 7fee05294700  4 rocksdb: reusing log 57 from recycle list
=====

=====
2017-03-14 18:32:06.910308 7fedeb260700  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1489516326910303, "job": 27, "event": "table_file_deletion", "file_number": 69}
2017-03-14 18:32:06.910326 7fedeb260700  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1489516326910325, "job": 27, "event": "table_file_deletion", "file_number": 51}
2017-03-14 18:32:06.910343 7fedeb260700  4 rocksdb: EVENT_LOG_v1 {"time_micros": 1489516326910342, "job": 27, "event": "table_file_deletion", "file_number": 50}
2017-03-14 18:37:37.139963 7fedf3270700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 10
2017-03-14 18:37:37.144147 7fedf4a73700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 9
2017-03-14 18:37:37.179302 7fedf226e700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 10
2017-03-14 18:37:37.205677 7fedf2a6f700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 11
2017-03-14 18:37:37.226650 7fedf5274700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 11
2017-03-14 18:37:37.234589 7fedf3a71700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 11
2017-03-14 19:01:53.494364 7fee05294700  4 rocksdb: reusing log 61 from recycle list
======

======
2017-03-14 19:38:04.946439 7fedeba61700  4 rocksdb: (Original Log Time 2017/03/14-19:38:04.946355) EVENT_LOG_v1 {"time_micros": 1489520284946348, "job": 29, "event": "flush_finished", "lsm_state": [2, 4, 13, 0, 0, 0, 0], "immutable_memtables": 0}
2017-03-14 19:38:04.946441 7fedeba61700  4 rocksdb: (Original Log Time 2017/03/14-19:38:04.946383) [default] Level summary: base level 1 max bytes base 268435456 files[2 4 13 0 0 0 0] max score 0.85

2017-03-14 19:38:04.946461 7fedeba61700  4 rocksdb: [JOB 29] Try to delete WAL files size 244060984, prev total WAL file size 247581163, number of live WAL files 2.

2017-03-14 20:01:43.916418 7fedf4272700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 10
2017-03-14 20:01:43.951939 7fedf126c700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 11
2017-03-14 20:01:43.960599 7fedf3270700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 11
2017-03-14 20:01:43.969409 7fedf3a71700 -1 bdev(/var/lib/ceph/osd/ceph-73/block) aio_submit retries 11
2017-03-14 20:13:04.291160 7fee05294700  4 rocksdb: reusing log 85 from recycle list

2017-03-14 20:13:04.291254 7fee05294700  4 rocksdb: [default] New memtable created with log file: #89. Immutable memtables: 0.
=====

Thanks

On Wed, Mar 15, 2017 at 11:18 AM, nokia ceph <nokiacephusers@xxxxxxxxx> wrote:
Hello,
Can we get any update for this problem?

Thanks

On Thu, Mar 2, 2017 at 2:16 PM, nokia ceph <nokiacephusers@xxxxxxxxx> wrote:
Hello,

Env:- v11.2.0 - bluestore - EC 3 + 1

We are getting below entries both in /var/log/messages and osd logs. May I know what is the impact of the below message and as these message were flooded in osd and sys logs. 

~~~
2017-03-01 13:00:59.938839 7f6c96915700 -1 bdev(/var/lib/ceph/osd/ceph-0/block)
aio_submit retries 2

2017-03-01 13:00:59.940939 7f6c96915700 -1
bdev(/var/lib/ceph/osd/ceph-0/block) aio_submit retries 4

2017-03-01 13:00:59.941126 7f6c96915700 -1
bdev(/var/lib/ceph/osd/ceph-0/block) aio_submit retries 1
~~~

I found these messages during the activation of ceph-osd's

~~~ From /var/log/messages
Feb 27 13:59:46 PL6-CN2 sh: command_check_call: Running command: /usr/bin/systemctl start ceph-osd@39
Feb 27 13:59:46 PL6-CN2 systemd: Started Ceph disk activation: /dev/sdk2.
Feb 27 13:59:46 PL6-CN2 ceph-osd: 2017-02-27 13:59:46.540781 7f1f3f016700 -1 bdev(/var/lib/ceph/osd/ceph-39/block) aio_submit retries 9
Feb 27 13:59:46 PL6-CN2 ceph-osd: 2017-02-27 13:59:46.544670 7f1f3f016700 -1 bdev(/var/lib/ceph/osd/ceph-39/block) aio_submit retries 2
Feb 27 13:59:46 PL6-CN2 ceph-osd: 2017-02-27 13:59:46.544854 7f1f3f016700 -1 bdev(/var/lib/ceph/osd/ceph-39/block) aio_submit retries 1
Feb 27 13:59:47 PL6-CN2 kernel: sdl: sdl1
Feb 27 13:59:47 PL6-CN2 kernel: sdl: sdl1
Feb 27 13:59:48 PL6-CN2 kernel: sdl: sdl1 sdl2
Feb 27 13:59:48 PL6-CN2 systemd: Cannot add dependency job for unit microcode.service, ignoring: Unit is not loaded properly: Invalid argument.
Feb 27 13:59:48 PL6-CN2 systemd: Starting Ceph disk activation: /dev/sdl2...
~~~

At the same time on OSD logs:-- /var/log/ceph/ceph-osd.43.log-20170228.gz

2017-02-27 14:00:17.121460 7f147351e940  0 osd.43 0 crush map has features 2199057072128, adjusting msgr requires for clients
2017-02-27 14:00:17.121466 7f147351e940  0 osd.43 0 crush map has features 2199057072128 was 8705, adjusting msgr requires for mons
2017-02-27 14:00:17.121468 7f147351e940  0 osd.43 0 crush map has features 2199057072128, adjusting msgr requires for osds
2017-02-27 14:00:17.121511 7f147351e940  0 osd.43 0 load_pgs
2017-02-27 14:00:17.121514 7f147351e940  0 osd.43 0 load_pgs opened 0 pgs
2017-02-27 14:00:17.121517 7f147351e940  0 osd.43 0 using 1 op queue with priority op cut off at 64.
2017-02-27 14:00:17.122364 7f147351e940 -1 osd.43 0 log_to_monitors {default=true}
2017-02-27 14:00:18.371762 7f147351e940  0 osd.43 0 done with init, starting boot process
2017-02-27 14:00:18.486559 7f1459952700 -1 bdev(/var/lib/ceph/osd/ceph-43/block) aio_submit retries 7
2017-02-27 14:00:18.488770 7f1459952700 -1 bdev(/var/lib/ceph/osd/ceph-43/block) aio_submit retries 4
2017-02-27 14:00:18.489306 7f1459952700 -1 bdev(/var/lib/ceph/osd/ceph-43/block) aio_submit retries 2
2017-02-27 14:00:18.489826 7f1459952700 -1 bdev(/var/lib/ceph/osd/ceph-43/block) aio_submit retries 2
<snip>
..
<snip>
2017-02-27 14:00:18.583234 7f145814f700  0 osd.43 93 crush map has features 2200130813952, adjusting msgr requires for clients
2017-02-27 14:00:18.583257 7f145814f700  0 osd.43 93 crush map has features 2200130813952 was 2199057080833, adjusting msgr requires for mons
2017-02-27 14:00:18.583271 7f145814f700  0 osd.43 93 crush map has features 2200130813952, adjusting msgr requires for osds
~~~~

As per my understanding on a bluestore device, we can write with both O_DIRECT and aio way. For some reasons, bdev can't able to commit with aio type. 

~~~
"ms_type": "async"
~~~

Need your suggestion how to skip these messages. 

Thanks

_______________________________________________
ceph-users mailing list
ceph-users@xxxxxxxxxxxxxx
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com