create: add tcmur_cmd_time_out option support

lxbsz commented 5 years ago

What does this PR achieve? Why do we need it?

Set the tcmur_cmd_time_out=43s as default, which is larger than each IO's timeout value(default is 30s) in the client/initiator side, and at the same time it will be larger than 42s, the Gluster ping timeout.

Does this PR fix issues?

No

Notes for the reviewer

This depends on the following two PRs: [1] https://github.com/open-iscsi/configshell-fb/pull/47 [2] https://github.com/open-iscsi/tcmu-runner/pull/568

lxbsz commented 5 years ago

@pkalever For this we need to get the tcmu-runner's PR merged first. So let's wait for a moment and then I will rebase it.. Thanks.

lxbsz commented 5 years ago

@pkalever The tcmu-runner PR has been merged. Reabsed this and made it settable via the gluster-block cli and set the default as 43s.

Please review thanks.

lxbsz commented 5 years ago

Update the tcmu-runner new release version(1.5.0) check, which has contained the log stuck patch set we needed.

Thanks,

pkalever commented 5 years ago

@lxbsz Could you please rebase this on master. I will review this now.

lxbsz commented 5 years ago

@lxbsz Could you please rebase this on master. I will review this now.

@pkalever Done, thanks.

pkalever commented 5 years ago

@lxbsz while the patch works and respects tcmur_cmd_time_out=X both at tcmu-runner and gluster-block, this patch doesn't fail with the version check when one of the nodes doesn't have gluster-block tcmu-timeout capability.

[root@localhost gluster-block]# cat /sys/kernel/config/target/core/user_1/block1/info 
Status: ACTIVATED  Max Queue Depth: 0  SectorSize: 512  HwMaxSectors: 128
        Config: glfs/sample@localhost/block-store/6da03d26-9323-45c0-97a8-28f32327470f;tcmur_cmd_time_out=53 Size: 1048576 MaxDataAreaMB: 1024

tcmu-runner.log:

2019-10-31 13:14:22.753 7189 [CRIT] tcmu_set_log_level:106: log level now is DEBUG
2019-10-31 13:14:22.753 7189 [DEBUG] tcmu_resetup_log_file:728: No changes to current log_dir: /var/log, skipping it.
2019-10-31 13:14:22.838 7189 [DEBUG] dyn_config_start:442: event->mask: 0x2
2019-10-31 13:14:22.838 7189 [DEBUG] tcmu_set_log_level:97: No changes to current log_level: DEBUG, skipping it.
2019-10-31 13:14:22.838 7189 [DEBUG] tcmu_resetup_log_file:728: No changes to current log_dir: /var/log, skipping it.
2019-10-31 13:14:35.757 7189 [DEBUG] handle_netlink:202: cmd 1. Got header version 2. Supported 2.
2019-10-31 13:14:35.757 7189 [DEBUG] parse_tcmu_runner_args:904 glfs/block1: Using tcmur_cmd_timeout 53
2019-10-31 13:14:35.757 7189 [DEBUG] parse_tcmu_runner_args:923 glfs/block1: Updated cfgstring: glfs/sample@localhost/block-store/6da03d26-9323-45c0-97a8-28f32327470f.
2019-10-31 13:14:35.758 7189 [DEBUG] dev_added:984 glfs/block1: Got block_size 512, size in bytes 1048576
2019-10-31 13:14:35.763 7189 [DEBUG] tcmur_get_time:632 glfs/block1: Current time 3653 secs.

How to reproduce:

checkout to master branch in one of the node and compile, reload, restart gluster-blockd
create a block from one of other nodes which has tcmur-timeout capability
it retuns success

root@localhost gluster-block]# gluster-block create sample/block3 ha 3 tcmur-timeout 53 192.168.122.78,192.168.122.230,192.168.122.63 1MiB
IQN: iqn.2016-12.org.gluster-block:25031e4c-ee84-4acf-a788-3245a5bb420a
PORTAL(S):  192.168.122.78:3260 192.168.122.230:3260 192.168.122.63:3260
RESULT: SUCCESS

Expected: create command Fail with meaningful hint.

Thanks!

pkalever commented 5 years ago

@lxbsz the PR looks clean, except it is missing a test case addition to the basic.t

My test failed:

[root@localhost gluster-block]# gluster-block create sample/block1 ha 3 tcmur-timeout 53 192.168.122.78,192.168.122.230,192.168.122.63 1MiB                                                                                                   
Did not receive any response from gluster-block daemon. Please check log files to find the reason

[root@localhost gluster-block]# systemctl status gluster-blockd                                                                                                                                                                      [18/1883]
● gluster-blockd.service - Gluster block storage utility                                                                                                                                                                                      
   Loaded: loaded (/usr/local/lib/systemd/system/gluster-blockd.service; disabled; vendor preset: disabled)                                                                                                                                   
   Active: failed (Result: timeout) since Thu 2019-10-31 18:04:46 IST; 1min 13s ago                                                                                                                                                           
  Process: 16341 ExecStart=/usr/local/sbin/gluster-blockd --glfs-lru-count $GB_GLFS_LRU_COUNT --log-level $GB_LOG_LEVEL $GB_EXTRA_ARGS (code=killed, signal=KILL)                                                                             
 Main PID: 16341 (code=killed, signal=KILL)                                                                                                                                                                                                   

Oct 31 18:02:09 localhost.localdomain gluster-blockd[16341]: Parameter auto_enable_tpgt is now 'false'.                                                                                                                                       
Oct 31 18:02:09 localhost.localdomain gluster-blockd[16341]: Parameter auto_add_default_portal is now 'false'.                                                                                                                                
Oct 31 18:02:09 localhost.localdomain gluster-blockd[16341]: Parameter auto_save_on_exit is now 'false'.                                                                                                                                      
Oct 31 18:02:09 localhost.localdomain gluster-blockd[16341]: Parameter logfile is now '/var/log/gluster-block/gluster-block-configshell.log'.                                                                                                 
Oct 31 18:03:16 localhost.localdomain systemd[1]: Stopping Gluster block storage utility...
Oct 31 18:04:46 localhost.localdomain systemd[1]: gluster-blockd.service: State 'stop-sigterm' timed out. Killing.
Oct 31 18:04:46 localhost.localdomain systemd[1]: gluster-blockd.service: Killing process 16341 (gluster-blockd) with signal SIGKILL.
Oct 31 18:04:46 localhost.localdomain systemd[1]: gluster-blockd.service: Main process exited, code=killed, status=9/KILL
Oct 31 18:04:46 localhost.localdomain systemd[1]: gluster-blockd.service: Failed with result 'timeout'.
Oct 31 18:04:46 localhost.localdomain systemd[1]: Stopped Gluster block storage utility.

When all nodes are upgraded this happened to me, I expect a successful create, but it didn't happen.

Thanks!

pkalever commented 5 years ago

@lxbsz

This logs looks duplicating:

[2019-10-31 12:46:50.967236] INFO: the 'tcmur_cmd_timeout' needs atleast configshell >= 1.1.25, so disabling tis capability [at capabilities.c+48 :<gbTcmurCmdTimeoutDependenciesVersionCheck>]
[2019-10-31 12:46:50.967274] WARNING: tcmur timeout needs atleast configshell >=1.1.25 and tcmu-runner >= 1.5.0, so disabling its capability [at capabilities.c+182 :<gbSetCapabilties>]

Lets only have one at a time :-)

pkalever commented 5 years ago

@lxbsz not sure, what is wrong, I have retested it and it works well for me now. Considering its a setup issue for now.

Please do below before I merge:

add a test case
remove the duplicated log entries mentioned above.

Rest all looks good to me.

Thanks!

lxbsz commented 5 years ago

@lxbsz not sure, what is wrong, I have retested it and it works well for me now. Considering its a setup issue for now.

I hit the similar issue before many times. Sometimes just reboot the gluster-blockd service it seemed won't work from my other tests before. It seemed that the systemctl restart won't work correctly without reloading new binary code and I needed to clean the node by rebooting.

Please do below before I merge:

add a test case

remove the duplicated log entries mentioned above.

Rest all looks good to me.

Thanks!

@pkalever
Done, thanks.

pkalever commented 4 years ago

@lxbsz the PR looks good, but one last thing to discuss before I hit the merge button:

[root@localhost gluster-block]# gluster-block info sample/block13                                                                                                        
NAME: block13                                                                                                                                                            
VOLUME: sample                                                                                                                                                           
GBID: 32648e9e-c23f-4fcc-808c-f0691e253ced                                                                                                                               
SIZE: 1.0 MiB                                                                       
BLKSIZE: 0                                                                                                                                                               
RINGBUFFER: 0 MiB                                                                                                                                                        
HA: 3                                                                                                                                                                    
PRIOPATH: 192.168.122.78                                                                                                                                                 
TCMURCMDTIMEOUT: 56 Seconds                                                                                                                                              
PASSWORD:                                                                                                                                                                
EXPORTED ON: 192.168.122.63 192.168.122.78 192.168.122.230                                                                                                               

[root@localhost gluster-block]# gluster-block info sample/block13 --json-pretty                                                                                          
{                                                                                                                                                                        
  "NAME":"block13",                                                                                                                                                      
  "VOLUME":"sample",                                                                                                                                                     
  "GBID":"32648e9e-c23f-4fcc-808c-f0691e253ced",                                                                                                                         
  "SIZE":"1.0 MiB",                                                                                                                                                      
  "BLKSIZE":0,                                                                                                                                                           
  "RINGBUFFER":"0 MiB",
  "HA":3,
  "PRIOPATH":"192.168.122.78",
  "TCMURCMDTIMEOUT":"56 Seconds",
  "PASSWORD":"",
  "EXPORTED ON":[
    "192.168.122.63",
    "192.168.122.78",
    "192.168.122.230"
  ]
}

BLKSIZE 0 and RINGBUFFER: 0 ? does this make sense ?

Can we fetch the defaults and print it here ?

Thanks!

lxbsz commented 4 years ago

@lxbsz the PR looks good, but one last thing to discuss before I hit the merge button: [...] BLKSIZE 0 and RINGBUFFER: 0 ? does this make sense ?

Can we fetch the defaults and print it here ?

Not very clear here, do you mean remove the "MiB" suffix ? Currently this is just as the "SIZE":"1.0 MiB", does.

Thanks!

pkalever commented 4 years ago

@lxbsz the PR looks good, but one last thing to discuss before I hit the merge button: [...] BLKSIZE 0 and RINGBUFFER: 0 ? does this make sense ? Can we fetch the defaults and print it here ?

Not very clear here, do you mean remove the "MiB" suffix ? Currently this is just as the "SIZE":"1.0 MiB", does.

@lxbsz No really, SIZE 0 cannot be accepted for block volumes. What I mean is, the BLKSIZE 0 is not true actually, when we do not give block-size as agrument then the block-size will use defaults right ? hence printing 0 is wrong. Same with RINGBUFFER.

lxbsz commented 4 years ago

@lxbsz the PR looks good, but one last thing to discuss before I hit the merge button: [...] BLKSIZE 0 and RINGBUFFER: 0 ? does this make sense ? Can we fetch the defaults and print it here ?

Not very clear here, do you mean remove the "MiB" suffix ? Currently this is just as the "SIZE":"1.0 MiB", does.

@lxbsz No really, SIZE 0 cannot be accepted for block volumes. What I mean is, the BLKSIZE 0 is not true actually, when we do not give block-size as agrument then the block-size will use defaults right ? hence printing 0 is wrong. Same with RINGBUFFER.

Ah, get you :-). You are right, will fix it.

lxbsz commented 4 years ago

@pkalever Fixed it with setting the default value to 64MiB if the ring-buffer option is omitted. This will make sure that the meta data are the same from mount point's ./block-store/ and gluster-block info.

pkalever commented 4 years ago

@lxbsz yep this makesense to me. Please open a new issue for this so that it won't be missed later.

Sorry again for pausing the merge for a moment, I know this is comming late, but better late than never, I was thinking may be 'tcmur-timeout' option naming can be bit generalized at cli, may be as io-timeout or something meaningful ? if we can take example from glusterfs which named it as ping-timeout, simple huh ? just a thought, let me know what you think about this, I will wait on you.

Thanks!

lxbsz commented 4 years ago

@lxbsz yep this makesense to me. Please open a new issue for this so that it won't be missed later.

Sorry again for pausing the merge for a moment, I know this is comming late, but better late than never, I was thinking may be 'tcmur-timeout' option naming can be bit generalized at cli, may be as io-timeout or something meaningful ? if we can take example from glusterfs which named it as ping-timeout, simple huh ? just a thought, let me know what you think about this, I will wait on you.

Yeah, it makes sense too :-)

Since the tcmur-timeout is one option in LIO/TCMU, which is waiting for the inflight IOs to be finished in tcmu-runner/glfs. So will it be better with a name fio-timeout. Thefhere meansflight or fired.

BRs

pkalever commented 4 years ago

@lxbsz yep this makesense to me. Please open a new issue for this so that it won't be missed later. Sorry again for pausing the merge for a moment, I know this is comming late, but better late than never, I was thinking may be 'tcmur-timeout' option naming can be bit generalized at cli, may be as io-timeout or something meaningful ? if we can take example from glusterfs which named it as ping-timeout, simple huh ? just a thought, let me know what you think about this, I will wait on you.

Yeah, it makes sense too :-)

Since the tcmur-timeout is one option in LIO/TCMU, which is waiting for the inflight IOs to be finished in tcmu-runner/glfs. So will it be better with a name fio-timeout. Thefhere meansflight or fired.

Why not keep it same as glusterfs ?

Option: network.ping-timeout
Default Value: 42
Description: Time duration for which the client waits to check if the server is responsive.

May change this to, something that works for gluster-block as:

Option: ping-timeout
Default Value: 43
Description: Time duration for which the tcmu-runner waits to check if the IO from gluster block hosting volume server is responsive. Ideally this value should be kept larger than both IO timeout value (default is 30s) in the iscsi client/initiator side and the gluster ping timeout (default is 42s).

Also @lxbsz make a check, if user supplys any value smaller than 43, do not accepting it would be a good idea.

And also in what case some one want to teak/change it ? Atleast I cannot recollect why this should be a tunable option available for users, can you please give bit more details on this ?

Thanks!

lxbsz commented 4 years ago

@lxbsz yep this makesense to me. Please open a new issue for this so that it won't be missed later. Sorry again for pausing the merge for a moment, I know this is comming late, but better late than never, I was thinking may be 'tcmur-timeout' option naming can be bit generalized at cli, may be as io-timeout or something meaningful ? if we can take example from glusterfs which named it as ping-timeout, simple huh ? just a thought, let me know what you think about this, I will wait on you.

Yeah, it makes sense too :-) Since the tcmur-timeout is one option in LIO/TCMU, which is waiting for the inflight IOs to be finished in tcmu-runner/glfs. So will it be better with a name fio-timeout. Thefhere meansflight or fired.

Why not keep it same as glusterfs ?

The tcmur-timeout here is not exactly only for the the ping-timeout, it is something like max(ping-timeout, IO timeout in kernel space).

Option: network.ping-timeout
Default Value: 42
Description: Time duration for which the client waits to check if the server is responsive.
May change this to, something that works for gluster-block as:
Option: ping-timeout
Default Value: 43
Description: Time duration for which the tcmu-runner waits to check if the IO from gluster block hosting volume server is responsive. Ideally this value should be kept larger than both IO timeout value (default is 30s) in the iscsi client/initiator side and the gluster ping timeout (default is 42s).
Also @lxbsz make a check, if user supplys any value smaller than 43, do not accepting it would be a good idea.

And also in what case some one want to teak/change it ? Atleast I cannot recollect why this should be a tunable option available for users, can you please give bit more details on this ?

As above, what if the IO timeout in kernel space is changed ? We need to enlarge the tcmur-timeout here too in some cases, such as for some DB use cases.

As default we can recommend that the tcmur-timeout here should >= 42, which is max(default ping-timeout, default IO timeout in kernel space).

Thanks!

pkalever commented 4 years ago

@lxbsz ok. Just name it as io-timeout and add the decription mentioned above.

Description: Time duration for which the tcmu-runner waits to check if the IO from gluster block hosting volume server is responsive. Ideally this value should be kept larger than both IO timeout value (default is 30s) in the iscsi client/initiator side and the gluster ping timeout (default is 42s).

lxbsz commented 4 years ago

@lxbsz ok. Just name it as io-timeout and add the decription mentioned above.

Description: Time duration for which the tcmu-runner waits to check if the IO from gluster block hosting volume server is responsive. Ideally this value should be kept larger than both IO timeout value (default is 30s) in the iscsi client/initiator side and the gluster ping timeout (default is 42s).

Done. Thanks.

lxbsz commented 4 years ago

@pkalever Tested the create/info/replace/genconfig/cap mismatch, all work for me. Thanks.

pkalever commented 4 years ago

@lxbsz fixed few minor code styles, please update this PR with below patch and I will merge it. Thanks! 0001-create-add-tcmur_cmd_time_out-option-support.txt

pkalever commented 4 years ago

@lxbsz merged now, thanks!

gluster / gluster-block