[ofa-general] opensm hang and osmtest report ERR 0130
Yevgeny Kliteynik
kliteyn at dev.mellanox.co.il
Sun Aug 10 23:19:27 PDT 2008
Wen Hao Wang wrote:
> Hal and Yevgeny:
>
> Thanks for your comments!
>
> I have disabled the embedded SM on Cisco switch, and run opensm without
> argument on one of my servers. The command gave "subnet up" message and
> hung there. Command output of osmtest also contained errors, while the
> latest line was /OSMTEST: TEST "All Validations" PASS/. Would you please
> have a look at this, I am not sure whether all have succeeded, or there
> is still something wrong.
It's OK, everything worked fine.
Osmtest does some wrong stuff intentionally, just to see that
opensm can handle it correctly - note all the "expecting errors"
messages in the osmtest log. Same goes for errors in the opensm
log, such as invalid sm_key - osmtest intentionally sends these
"wrong" packets.
-- Yevgeny
> [root at gaia-07 ~]# opensm
> -------------------------------------------------
> OpenSM 3.1.11
> Command Line Arguments:
> Log File: /var/log/opensm.log
> -------------------------------------------------
> OpenSM 3.1.11
>
> Using default GUID 0x2c90300013371
> Entering MASTER state
>
> SUBNET UP
>
> (Never end up ...)
> [root at gaia-07 ~]# osmtest -f c
>
> Command Line Arguments
> Done with args
> Flow = Create Inventory
> Aug 11 03:43:50 294507 [1B8CC3B0] 0x7f -> Setting log level to: 0x03
> Aug 11 03:43:50 313268 [1B8CC3B0] 0x02 -> osm_vendor_bind: Binding to
> port 0x2c90300013371
> Aug 11 03:43:50 336271 [1B8CC3B0] 0x02 ->
> osmtest_validate_sa_class_port_info:
> -----------------------------
> SA Class Port Info:
> base_ver:1
> class_ver:2
> cap_mask:0x2602
> cap_mask2:0x0
> resp_time_val:0x10
> -----------------------------
> OSMTEST: TEST "Create Inventory" PASS
> [root at gaia-07 ~]# osmtest -f a
>
> Command Line Arguments
> Done with args
> Flow = All Validations
> Aug 11 03:33:21 711113 [79D093B0] 0x7f -> Setting log level to: 0x03
> Aug 11 03:33:21 729683 [79D093B0] 0x02 -> osm_vendor_bind: Binding to
> port 0x2c90300013371
> Aug 11 03:33:21 752518 [79D093B0] 0x02 ->
> osmtest_validate_sa_class_port_info:
> -----------------------------
> SA Class Port Info:
> base_ver:1
> class_ver:2
> cap_mask:0x2602
> cap_mask2:0x0
> resp_time_val:0x10
> -----------------------------
> Aug 11 03:33:21 755242 [79D093B0] 0x01 -> osmtest_get_multipath_rec: [[
> ===== Expecting Errors - START =====
> Aug 11 03:33:21 755337 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0002
> Aug 11 03:33:21 755344 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 755356 [79D093B0] 0x01 -> osmtest_get_multipath_rec: ERR
> 0069: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 755364 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> Remote error = IB_SA_MAD_STATUS_REQ_INVALID
> Aug 11 03:33:21 755370 [79D093B0] 0x01 -> osmtest_get_multipath_rec: Got
> error IB_REMOTE_ERROR
> Aug 11 03:33:21 755374 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> ===== Expecting Errors - END ===== ]]
> Aug 11 03:33:21 755378 [79D093B0] 0x01 -> osmtest_get_multipath_rec: [[
> ===== Expecting Errors - START =====
> Aug 11 03:33:21 755469 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0002
> Aug 11 03:33:21 755475 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 755486 [79D093B0] 0x01 -> osmtest_get_multipath_rec: ERR
> 0069: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 755491 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> Remote error = IB_SA_MAD_STATUS_REQ_INVALID
> Aug 11 03:33:21 755496 [79D093B0] 0x01 -> osmtest_get_multipath_rec: Got
> error IB_REMOTE_ERROR
> Aug 11 03:33:21 755500 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> ===== Expecting Errors - END ===== ]]
> Aug 11 03:33:21 755507 [79D093B0] 0x01 -> osmtest_get_multipath_rec: [[
> ===== Expecting Errors - START =====
> Aug 11 03:33:21 755583 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0005
> Aug 11 03:33:21 755589 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 755599 [79D093B0] 0x01 -> osmtest_get_multipath_rec: ERR
> 0069: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 755604 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> Remote error = IB_SA_MAD_STATUS_INVALID_GID
> Aug 11 03:33:21 755609 [79D093B0] 0x01 -> osmtest_get_multipath_rec: Got
> error IB_REMOTE_ERROR
> Aug 11 03:33:21 755613 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> ===== Expecting Errors - END ===== ]]
> Aug 11 03:33:21 755617 [79D093B0] 0x01 -> osmtest_get_multipath_rec: [[
> ===== Expecting Errors - START =====
> Aug 11 03:33:21 755692 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0005
> Aug 11 03:33:21 755699 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 755708 [79D093B0] 0x01 -> osmtest_get_multipath_rec: ERR
> 0069: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 755713 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> Remote error = IB_SA_MAD_STATUS_INVALID_GID
> Aug 11 03:33:21 755718 [79D093B0] 0x01 -> osmtest_get_multipath_rec: Got
> error IB_REMOTE_ERROR
> Aug 11 03:33:21 755722 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> ===== Expecting Errors - END ===== ]]
> Aug 11 03:33:21 756481 [79D093B0] 0x01 -> osmtest_get_multipath_rec: [[
> ===== Expecting Errors - START =====
> Aug 11 03:33:21 756557 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0002
> Aug 11 03:33:21 756564 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 756574 [79D093B0] 0x01 ->
> osmtest_get_pkeytbl_rec_by_lid: ERR 007F: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 756579 [79D093B0] 0x01 ->
> osmtest_get_pkeytbl_rec_by_lid: Remote error = IB_SA_MAD_STATUS_REQ_INVALID
> Aug 11 03:33:21 756584 [79D093B0] 0x01 -> osmtest_get_multipath_rec: Got
> error IB_INSUFFICIENT_MEMORY
> Aug 11 03:33:21 756588 [79D093B0] 0x01 -> osmtest_get_multipath_rec:
> ===== Expecting Errors - END ===== ]]
> Aug 11 03:33:21 757513 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0C00
> Aug 11 03:33:21 757520 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 757530 [79D093B0] 0x01 -> osmtest_sminfo_record_request:
> ERR 008D: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 757536 [79D093B0] 0x01 -> osmtest_sminfo_record_request:
> Remote error = IB_MAD_STATUS_UNSUP_METHOD_ATTR
> Aug 11 03:33:21 757541 [79D093B0] 0x01 -> osmtest_sminfo_request: IS
> EXPECTED ERROR ^^^^
> Aug 11 03:33:21 759085 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0C00
> Aug 11 03:33:21 759092 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 759102 [79D093B0] 0x01 -> osmtest_informinfo_request:
> ERR 008F: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 759107 [79D093B0] 0x01 -> osmtest_informinfo_request:
> Remote error = IB_MAD_STATUS_UNSUP_METHOD_ATTR
> Aug 11 03:33:21 759112 [79D093B0] 0x01 -> osmtest_informinfo_request:
> InformInfoRecord IS EXPECTED ERROR ^^^^
> Aug 11 03:33:21 759248 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0C00
> Aug 11 03:33:21 759254 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 759264 [79D093B0] 0x01 -> osmtest_informinfo_request:
> ERR 008F: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 759269 [79D093B0] 0x01 -> osmtest_informinfo_request:
> Remote error = IB_MAD_STATUS_UNSUP_METHOD_ATTR
> Aug 11 03:33:21 759274 [79D093B0] 0x01 -> osmtest_informinfo_request:
> InformInfo IS EXPECTED ERROR ^^^^
> Aug 11 03:33:21 759353 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0002
> Aug 11 03:33:21 759360 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:21 759370 [79D093B0] 0x01 -> osmtest_informinfo_request:
> ERR 008F: ib_query failed (IB_REMOTE_ERROR)
> Aug 11 03:33:21 759375 [79D093B0] 0x01 -> osmtest_informinfo_request:
> Remote error = IB_SA_MAD_STATUS_REQ_INVALID
> Aug 11 03:33:21 759379 [79D093B0] 0x01 -> osmtest_informinfo_request:
> InformInfo UnSubscribe IS EXPECTED ERROR ^^^^
> Aug 11 03:33:21 796288 [79D093B0] 0x02 -> osmtest_wrong_sm_key_ignored:
> Trying PortInfoRecord for port with LID 0x3 Num:0x1
> Aug 11 03:33:21 796292 [79D093B0] 0x01 -> osmtest_wrong_sm_key_ignored:
> [[ ===== Expecting Errors - START =====
> Aug 11 03:33:25 793475 [41BC7940] 0x01 -> umad_receiver: ERR 5409: send
> completed with error (method=0x1 attr=0x12 trans_id=0xca00000206) --
> dropping
> Aug 11 03:33:25 793488 [41BC7940] 0x01 -> umad_receiver: ERR 5410: class
> 0x3 LID 0x3
> Aug 11 03:33:25 793494 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_TIMEOUT)
> Aug 11 03:33:25 793507 [79D093B0] 0x01 -> osmtest_wrong_sm_key_ignored:
> ===== Expecting Errors - END ===== ]]
> Aug 11 03:33:25 793525 [79D093B0] 0x02 -> osmt_register_service:
> Registering service: name: osmt.srvc.1804289383.10242 id: 0x6b8b1d65
> Aug 11 03:33:25 793615 [79D093B0] 0x02 -> osmt_register_service:
> Registering service: name: osmt.srvc.846930885.10242 id: 0x327afbc3
> Aug 11 03:33:25 793706 [79D093B0] 0x02 -> osmt_register_service:
> Registering service: name: osmt.srvc.1681692775.10242 id: 0x643c7065
> Aug 11 03:33:25 793783 [79D093B0] 0x02 ->
> osmt_register_service_with_data: Registering service: name:
> osmt.srvc.1714636912.10242 id: 0x6633206e
> Aug 11 03:33:25 793869 [79D093B0] 0x02 ->
> osmt_register_service_with_data: Registering service: name:
> osmt.srvc.1714636912.10242 id: 0x6633206e
> Aug 11 03:33:25 793947 [79D093B0] 0x02 ->
> osmt_register_service_with_full_key: Registering service: name:
> osmt.srvc.424238330.10242 id: 0x194934f8
> Aug 11 03:33:25 794032 [79D093B0] 0x02 ->
> osmt_register_service_with_full_key: Registering service: name:
> osmt.srvc.719885380.10242 id: 0x194934f8
> Aug 11 03:33:35 795534 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 795548 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 795580 [79D093B0] 0x01 -> osmt_get_service_by_name: IS
> EXPECTED ERROR ^^^^
> Aug 11 03:33:35 795729 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 795736 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 795748 [79D093B0] 0x01 -> osmt_get_service_by_id: IS
> EXPECTED ERROR ^^^^
> Aug 11 03:33:35 795967 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 795974 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 795987 [79D093B0] 0x01 ->
> osmt_get_service_by_id_and_name: IS EXPECTED ERROR ^^^^
> Aug 11 03:33:35 796054 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 796060 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 796073 [79D093B0] 0x01 ->
> osmt_get_service_by_id_and_name: IS EXPECTED ERROR ^^^^
> Aug 11 03:33:35 796141 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 796147 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 796160 [79D093B0] 0x01 -> osmt_get_service_by_name: IS
> EXPECTED ERROR ^^^^
> Aug 11 03:33:35 796227 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 796233 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 796246 [79D093B0] 0x01 -> osmt_get_service_by_name: IS
> EXPECTED ERROR ^^^^
> Aug 11 03:33:35 796389 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 796395 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 796407 [79D093B0] 0x01 ->
> osmt_get_service_by_name_and_key: IS EXPECTED ERROR ^^^^
> Aug 11 03:33:35 796476 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 796483 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 796495 [79D093B0] 0x01 ->
> osmt_get_service_by_name_and_key: IS EXPECTED ERROR ^^^^
> Aug 11 03:33:35 796679 [79D093B0] 0x02 -> osmt_delete_service_by_name:
> Trying to Delete service name: osmt.srvc.1804289383.10242
> Aug 11 03:33:35 796884 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 796891 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 796903 [79D093B0] 0x01 -> osmt_get_service_by_name: IS
> EXPECTED ERROR ^^^^
> Aug 11 03:33:35 796973 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 796979 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 796991 [79D093B0] 0x01 -> osmt_get_service_by_name: IS
> EXPECTED ERROR ^^^^
> Aug 11 03:33:35 797073 [79D093B0] 0x02 -> osmt_delete_service_by_name:
> Trying to Delete service name: osmt.srvc.424238330.10242
> Aug 11 03:33:35 797134 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 797140 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 797153 [79D093B0] 0x01 -> osmt_get_service_by_name: IS
> EXPECTED ERROR ^^^^
> Aug 11 03:33:35 797220 [41BC7940] 0x01 -> __osmv_sa_mad_rcv_cb: ERR
> 5501: Remote error:0x0003
> Aug 11 03:33:35 797227 [41BC7940] 0x01 -> osmtest_query_res_cb: ERR
> 0003: Error on query (IB_REMOTE_ERROR)
> Aug 11 03:33:35 797239 [79D093B0] 0x01 -> osmt_run_service_records_flow:
> IS EXPECTED ERROR ^^^^
> Aug 11 03:33:35 797244 [79D093B0] 0x02 -> osmt_delete_service_by_name:
> Failed to delete service_name: osmt.srvc.424238330.10242
> Aug 11 03:33:35 797249 [79D093B0] 0x02 -> osmt_delete_service_by_name:
> Trying to Delete service name: osmt.srvc.1681692775.10242
> Aug 11 03:33:35 797399 [79D093B0] 0x02 -> osmt_delete_service_by_name:
> Trying to Delete service name: osmt.srvc.719885380.10242
> Aug 11 03:33:35 797547 [79D093B0] 0x02 -> osmtest_run: The event
> forwarding flow is not implemented yet!
> OSMTEST: TEST "All Validations" PASS
> [root at gaia-07 ~]# tail /var/log/opensm.log
> Aug 11 03:33:21 755421 [45F72940] 0x01 -> osm_mpr_rcv_process_cb: ERR
> 4512: __osm_mpr_rcv_get_end_points failed, not enough GIDs (nsrc 1 ndest 0)
> Aug 11 03:33:21 756141 [4196B940] 0x01 -> osm_pir_rcv_process: ERR 2109:
> No port found with LID 0xffff
> Aug 11 03:33:21 756525 [44B70940] 0x01 -> osm_pkey_rec_rcv_process ERR
> 4608: Request from non-trusted requester: Given SM_Key:0x0000000000000000
> Aug 11 03:33:21 756652 [45571940] 0x01 -> osm_pkey_rec_rcv_process: ERR
> 460B: No port found with LID 0xffff
> Aug 11 03:33:21 757479 [4196B940] 0x01 -> osm_smir_rcv_process: ERR
> 2804: Unsupported Method (SubnAdmSet)
> Aug 11 03:33:21 759319 [4236C940] 0x01 ->
> osm_infr_rcv_process_set_method: ERR 4307: Failed to UnSubscribe to non
> existing inform object
> Aug 11 03:33:21 796326 [47D75940] 0x01 ->
> __osm_sa_mad_ctrl_rcv_callback: ERR 1A04: Non-Zero SA MAD SM_Key:
> 0xf27000000000000 != SM_Key: 0x100000000000000; MAD ignored
> Aug 11 03:33:22 795985 [47D75940] 0x01 ->
> __osm_sa_mad_ctrl_rcv_callback: ERR 1A04: Non-Zero SA MAD SM_Key:
> 0xf27000000000000 != SM_Key: 0x100000000000000; MAD ignored
> Aug 11 03:33:23 795486 [47D75940] 0x01 ->
> __osm_sa_mad_ctrl_rcv_callback: ERR 1A04: Non-Zero SA MAD SM_Key:
> 0xf27000000000000 != SM_Key: 0x100000000000000; MAD ignored
> Aug 11 03:33:24 794985 [47D75940] 0x01 ->
> __osm_sa_mad_ctrl_rcv_callback: ERR 1A04: Non-Zero SA MAD SM_Key:
> 0xf27000000000000 != SM_Key: 0x100000000000000; MAD ignored
>
> Wen Hao Wang
> Email: wangwhao at cn.ibm.com
>
More information about the general
mailing list