From: Jorge A. A. Q. <jor...@cs...> - 2012-12-26 17:37:35
|
Thank you Bart I enable scsi tracing and get hundreds of lines of debug, but after reviewing it, I found this... I try to understand the problem but my capacity around scsi is limited Apparently two READ with same number trigger the problem, anybody have an idea about how correct this or where find more info? Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 2a 00 62 8f d0 00 00 00 01 00 00 00 00 00 00 00 *.b............. Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <WRITE(10)> (cmd ffff8800bad656c0), direction=1 (expected 1, set yes), bufflen=512, out_bufflen=0, (expected len 512, out expected len 0), flags=111 Dec 26 09:50:36 stlnx01 kernel: [32278]: scst: scst_cmd_done_local:1642:cmd ffff8800bad656c0, status 0, msg_status 0, host_status 0, driver_status 0, resp_data_len 0 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120048, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bad654b0, sess ffff88013819c430) Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 28 00 00 00 e0 00 00 00 80 00 00 00 00 00 00 00 (............... Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <READ(10)> (cmd ffff8800bad654b0), direction=2 (expected 2, set yes), bufflen=65536, out_bufflen=0, (expected len 65536, out expected len 0), flags=1011 Dec 26 09:50:36 stlnx01 kernel: [32278]: scst: scst_cmd_done_local:1642:cmd ffff8800bad654b0, status 0, msg_status 0, host_status 0, driver_status 0, resp_data_len 65536 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120049, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bad654b0, sess ffff88013819c430) Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 28 00 00 00 e0 10 00 00 02 00 00 00 00 00 00 00 (............... Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <READ(10)> (cmd ffff8800bad654b0), direction=2 (expected 2, set yes), bufflen=1024, out_bufflen=0, (expected len 1024, out expected len 0), flags=1011 Dec 26 09:50:36 stlnx01 kernel: [32278]: scst: scst_cmd_done_local:1642:cmd ffff8800bad654b0, status 0, msg_status 0, host_status 0, driver_status 0, resp_data_len 1024 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120050, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bad654b0, sess ffff88013819c430) Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 16 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <RESERVE> (cmd ffff8800bad654b0), direction=4 (expected 4, set yes), bufflen=0, out_bufflen=0, (expected len 0, out expected len 0), flags=b212 Dec 26 09:50:36 stlnx01 kernel: [0]: __scst_check_blocked_dev:6747:cmd ffff8800bad654b0 (tag 120050, op 16): blocking further cmds on dev disk03 due to serialized cmd Dec 26 09:50:36 stlnx01 kernel: [0]: scst_block_dev:6697:Device BLOCK (new count 1), dev disk03 Dec 26 09:50:36 stlnx01 kernel: [32278]: scst: scst_cmd_done_local:1642:cmd ffff8800bad654b0, status 0, msg_status 0, host_status 0, driver_status 0, resp_data_len 0 Dec 26 09:50:36 stlnx01 kernel: [0]: scst_check_unblock_dev:160:cmd ffff8800bad654b0 (tag 120050): unblocking dev disk03 Dec 26 09:50:36 stlnx01 kernel: [0]: scst_unblock_dev:6774:Device UNBLOCK(new 0), dev disk03 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120051, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bad652a0, sess ffff88013819c430) Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 28 00 00 00 e0 10 00 00 01 00 00 00 00 00 00 00 (............... Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <READ(10)> (cmd ffff8800bad652a0), direction=2 (expected 2, set yes), bufflen=512, out_bufflen=0, (expected len 512, out expected len 0), flags=1011 Dec 26 09:50:36 stlnx01 kernel: [32278]: scst: scst_cmd_done_local:1642:cmd ffff8800bad652a0, status 0, msg_status 0, host_status 0, driver_status 0, resp_data_len 512 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120052, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bad652a0, sess ffff88013819c430) Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 2a 00 00 00 e0 10 00 00 01 00 00 00 00 00 00 00 *............... Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <WRITE(10)> (cmd ffff8800bad652a0), direction=1 (expected 1, set yes), bufflen=512, out_bufflen=0, (expected len 512, out expected len 0), flags=111 Dec 26 09:50:36 stlnx01 kernel: [32278]: scst: scst_cmd_done_local:1642:cmd ffff8800bad652a0, status 0, msg_status 0, host_status 0, driver_status 0, resp_data_len 0 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120053, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bad65090, sess ffff88013819c430) Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 17 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................ Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <RELEASE> (cmd ffff8800bad65090), direction=4 (expected 4, set yes), bufflen=0, out_bufflen=0, (expected len 0, out expected len 0), flags=ba12 Dec 26 09:50:36 stlnx01 kernel: [0]: __scst_check_blocked_dev:6747:cmd ffff8800bad65090 (tag 120053, op 17): blocking further cmds on dev disk03 due to serialized cmd Dec 26 09:50:36 stlnx01 kernel: [0]: scst_block_dev:6697:Device BLOCK (new count 1), dev disk03 Dec 26 09:50:36 stlnx01 kernel: [32278]: scst: scst_cmd_done_local:1642:cmd ffff8800bad65090, status 0, msg_status 0, host_status 0, driver_status 0, resp_data_len 0 Dec 26 09:50:36 stlnx01 kernel: [0]: scst_check_unblock_dev:160:cmd ffff8800bad65090 (tag 120053): unblocking dev disk03 Dec 26 09:50:36 stlnx01 kernel: [0]: scst_unblock_dev:6774:Device UNBLOCK(new 0), dev disk03 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120054, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bae53d30, sess ffff88013819c430) Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 2a 00 62 a8 08 00 00 01 00 00 00 00 00 00 00 00 *.b............. Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <WRITE(10)> (cmd ffff8800bae53d30), direction=1 (expected 1, set yes), bufflen=131072, out_bufflen=0, (expected len 131072, out expected len 0), flags=111 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120055, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bae53b20, sess ffff88013819c430) Dec 26 09:50:36 stlnx01 kernel: [17829]: scst_cmd_init_done:354:Receiving CDB: Dec 26 09:50:36 stlnx01 kernel: (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F Dec 26 09:50:36 stlnx01 kernel: 0: 2a 00 62 a8 09 00 00 01 00 00 00 00 00 00 00 00 *.b............. Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_parse_cmd:666:op_name <WRITE(10)> (cmd ffff8800bae53b20), direction=1 (expected 1, set yes), bufflen=131072, out_bufflen=0, (expected len 131072, out expected len 0), flags=111 Dec 26 09:50:36 stlnx01 kernel: [32278]: scst: scst_cmd_done_local:1642:cmd ffff8800bae53d30, status 0, msg_status 0, host_status 0, driver_status 0, resp_data_len 0 Dec 26 09:50:36 stlnx01 kernel: [17829]: scst: scst_cmd_init_done:352:tag=120056, lun=0, CDB len=16, queue_type=1 (cmd ffff8800bae53910, sess ffff88013819c430) Right now I am using kernel version 3.6.11 and linux Gentoo, could somebody point me in the another combination who is using and working with VMWARE 5 ? Thanks in advance Jorge Arenas -----Original Message----- From: Bart Van Assche [mailto:bva...@ac...] Sent: martes, 25 de diciembre de 2012 11:42 a.m. To: Jorge A. Arenas Quezada Cc: scs...@li... Subject: Re: [Scst-devel] Kernel Errors Gento On 12/25/12 04:04, Jorge A. Arenas Quezada wrote: > As soon I start to copy something in the disk this appears in the logs > > Dec 24 20:55:24 stlnx01 kernel: [0]: __scst_check_blocked_dev:6747:cmd > ffff880137126780 (tag 168763, op 16): blocking further cmds on dev > disk03 due to serialized cmd > > Dec 24 20:55:24 stlnx01 kernel: [0]: scst_block_dev:6697:Device BLOCK > (new count 1), dev disk03 > > Dec 24 20:55:24 stlnx01 kernel: [0]: scst_check_unblock_dev:160:cmd > ffff880137126780 (tag 168763): unblocking dev disk03 > > Dec 24 20:55:24 stlnx01 kernel: [0]: scst_unblock_dev:6774:Device > UNBLOCK(new 0), dev disk03 > > Dec 24 20:55:24 stlnx01 kernel: [0]: __scst_check_blocked_dev:6747:cmd > ffff880136060260 (tag 168766, op 17): blocking further cmds on dev > disk03 due to serialized cmd > > Dec 24 20:55:24 stlnx01 kernel: [0]: scst_block_dev:6697:Device BLOCK > (new count 1), dev disk03 > > Dec 24 20:55:24 stlnx01 kernel: [0]: scst_check_unblock_dev:160:cmd > ffff880136060260 (tag 168766): unblocking dev disk03 > > Dec 24 20:55:24 stlnx01 kernel: [0]: scst_unblock_dev:6774:Device > UNBLOCK(new 0), dev disk03 > > Any pointers about where start to debugging? Or what to change to get > a better performance Enabling SCSI tracing briefly should reveal which SCSI commands trigger command serialization in SCST. Once it is clear what the cause is you can verify whether ESX can be configured such that it doesn't send these SCSI commands anymore. An example of how to enable command tracing in SCST briefly: echo add scsi > /sys/kernel/scst_tgt/trace_level; sleep 1; \ echo del scsi > /sys/kernel/scst_tgt/trace_level Bart. ________________________________ IMPORTANTE: Los documentos y archivos que se anexan a esta transmision, contienen informacion confidencial la cual es legalmente secreta. Esta informacion puede ser usada unicamente por el destinatario cuyo nombre aparece inserto en esta transmision. Si usted ha recibido esta transmision por error, notifiquenos inmediatamente por esta misma via, y borre el archivo y sus anexos. Se hace de su conocimiento por medio de esta nota, que cualquier divulgacion, copia, distribucion o toma de cualquier accion derivada de la informacion confiada en esta transmisin, queda estrictamente prohibido, el incumplimiento de esto genera responsabilidad legal. IMPORTANT: The documents and files attached to this transmission contain confidential information that must be kept secret by law. This information is for the exclusive use of the specified recipient whose name appears in this transmission. If you have received this message by mistake, please notify us immediately by return e-mail and delete the file and its attachments. You are hereby notified that any dissemination, copying, distribution or adoption of any action arising from the confidential information contained herein is strictly prohibited. Any violation will be penalized by law. |