[ServiceOrdersController.api_error] ActiveRecord::RecordNotFound: Couldn't find ServiceOrder

Hi,

May I know if anyone here knows the potential root cause of the following issue I’m facing?

I have an external application which integrates to MIQ using MIQ APIs. Essentially, my application does the following in sequence:

  1. Login and get x-auth-token using /api/auth?requester_type=ui
  2. Add provisioning catalog to cart using /api/service_orders/cart/service_requests/ with the x-auth-token retrieved from 1

The execution produced an error below from manageiq api.log:

[----] I, [2021-04-27T16:01:14.203739 #27696:3bea570] INFO – : MIQ(Api::AuthController.log_request_initiated)
[----] I, [2021-04-27T16:01:14.203882 #27696:3bea570] INFO – : MIQ(Api::AuthController.log_request) API Request: {:requested_at=>“2021-04-27 08:01:14 UTC”, :method=>“GET”, :url=>“link/api/auth?requester_type=ui”}
[----] I, [2021-04-27T16:01:14.676117 #27696:3bea570] INFO – : MIQ(Api::AuthController.log_request) Authentication: {:type=>“basic”, :token=>nil, :x_miq_group=>nil, :user=>“myldapuser@mydomain.com”}
[----] I, [2021-04-27T16:01:14.678525 #27696:3bea570] INFO – : MIQ(Api::AuthController.log_request) Authorization: {:user=>“myldapuser@mydomain.com”, :group=>“99UREG1_AD_SA”, :role=>“administrator”, :tenant=>“MyCompany”}
[----] I, [2021-04-27T16:01:14.680215 #27696:3bea570] INFO – : MIQ(Api::AuthController.log_request) Request: {:method=>:get, :action=>“read”, :fullpath=>"/api/auth?requester_type=ui", :url=>“link/api/auth?requester_type=ui”, :base=>“link”, :path=>"/api/auth", :prefix=>"/api", :version=>“4.0.0”, :api_prefix=>“link/api”, :collection=>“auth”, :c_suffix=>nil, :collection_id=>nil, :subcollection=>nil, :subcollection_id=>nil}
[----] I, [2021-04-27T16:01:14.680493 #27696:3bea570] INFO – : MIQ(Api::AuthController.log_request) Parameters: {“requester_type”=>“ui”, “action”=>“show”, “controller”=>“api/auth”, “format”=>“json”, “body”=>{}}
[----] I, [2021-04-27T16:01:14.681646 #27696:3bea570] INFO – : Generating Authentication Token for userid: myldapuser@mydomain.com requester_type: ui token_ttl: 3600
[----] I, [2021-04-27T16:01:14.683308 #27696:3bea570] INFO – : MIQ(Api::AuthController.log_request) Response: {:completed_at=>“2021-04-27 08:01:14 UTC”, :size=>“0.124 KBytes”, :time_taken=>“0.479 Seconds”, :status=>200}
[----] I, [2021-04-27T16:01:14.727325 #27696:3beb6c8] INFO – : MIQ(Api::ServiceOrdersController.log_request_initiated)
[----] I, [2021-04-27T16:01:14.727579 #27696:3beb6c8] INFO – : MIQ(Api::ServiceOrdersController.log_request) API Request: {:requested_at=>“2021-04-27 08:01:14 UTC”, :method=>“POST”, :url=>“link/api/service_orders/cart/service_requests/”}
[----] I, [2021-04-27T16:01:14.734191 #27696:3beb6c8] INFO – : MIQ(Api::ServiceOrdersController.log_request) Authentication: {:type=>“token”, :token=>“38f17ab822d30601e7087c8c03eacbfb”, :x_miq_group=>nil, :user=>“myldapuser@mydomain.com”}
[----] I, [2021-04-27T16:01:14.736791 #27696:3beb6c8] INFO – : MIQ(Api::ServiceOrdersController.log_request) Authorization: {:user=>“myldapuser@mydomain.com”, :group=>“99UREG1_AD_SA”, :role=>“administrator”, :tenant=>“MyCompany”}
[----] I, [2021-04-27T16:01:14.738744 #27696:3beb6c8] INFO – : MIQ(Api::ServiceOrdersController.log_request) Request: {:method=>:post, :action=>“add”, :fullpath=>"/api/service_orders/cart/service_requests", :url=>“link/api/service_orders/cart/service_requests”, :base=>“link”, :path=>"/api/service_orders/cart/service_requests", :prefix=>"/api", :version=>“4.0.0”, :api_prefix=>“link/api”, :collection=>“service_orders”, :c_suffix=>nil, :collection_id=>“cart”, :subcollection=>“service_requests”, :subcollection_id=>nil}
[----] I, [2021-04-27T16:01:14.739194 #27696:3beb6c8] INFO – : MIQ(Api::ServiceOrdersController.log_request) Parameters: {“action”=>“create”, “controller”=>“api/service_orders”, “format”=>“json”, “body”=>{“action”=>“add”, “resources”=>[{“service_name”=>“APPS”, “option_1_vm_target_name”=>“hostname”, “tag_1_app_group”=>“ipam_01”, “option_1_lobt”=>“ABC”, “option_1_vmsize”=>“2_16384”, “option_1_disk1”=>“0”, “option_1_disk2”=>“0”, “option_1_disk3”=>“0”, “option_1_mwdb”=>“NO”, “option_1_jbinstances”=>“1”, “option_1_maxscale”=>“f”, “option_1_rhelosver”=>“RHEL7_9”, “option_1_layerproduct”=>“t”, “option_1_harden”=>“t”, “option_1_env”=>“ENT”, “tag_1_dns_suffix”=>“vsi.mydomain.com”, “tag_1_dns_host”=>“route53.mydomain.com”, “tag_1_dns_port”=>“443”, “tag_1_gid”=>“201704”, “tag_1_os”=>“LIN”, “service_template_href”=>"/api/service_templates/22"}}]}}
[----] E, [2021-04-27T16:01:14.742980 #27696:3beb6c8] ERROR – : MIQ(Api::ServiceOrdersController.api_error) API Error
[----] E, [2021-04-27T16:01:14.743025 #27696:3beb6c8] ERROR – : MIQ(Api::ServiceOrdersController.api_error) ActiveRecord::RecordNotFound: Couldn’t find ServiceOrder

Strangely, if I go to MIQ itself and login to the self_service portal as the user that is triggering from the application, and then if I go back to my external application and try to trigger the flow as described above again the api calls went through.

Basically when I encounter this ServiceOrdersController.api_error, I’ll have to physically login to MIQ self_service portal as the user and then only triggering from external application will work.

Any idea?

@aikkai.lim Do you have a stack trace, perhaps in evm.log, or perhaps in the api.log, that shows the location of the error? I’m wondering if the service UI does some sort of follow-up API call to link things together that’s missing, whereas straight API access doesn’t have that.

IMO, if the API call doesn’t work directly, that is probably a bug. If you do have a stack trace, please open an issue here: Issues · ManageIQ/manageiq-api · GitHub