apache / cloudstack

Apache CloudStack is an opensource Infrastructure as a Service (IaaS) cloud computing platform
https://cloudstack.apache.org/
Apache License 2.0
2.09k stars 1.11k forks source link

listTemplate response error on ACS 4.17.2 #8111

Closed meisammaleki closed 10 months ago

meisammaleki commented 1 year ago

API request from whmcs server to cloudstack 4.17.2

4.17.2

OS / ENVIRONMENT

Centos 7

SUMMARY

we got error for some users when they want to see their panel. they got "please conntact with your system administrator". i have

STEPS TO REPRODUCE

I have examined the logs on the WHMCS side, and the output is as follows :

EXPECTED RESULTS

this is response for a customer without problem :

request : https://0.0.0.0:8443/client/api?templatefilter=featured&id=e82e822c-7bf3-4583-99d8-eed1d8424f28&command=listTemplates&apiKey=WUn_XCedTgkgsdofoJOwjfPCnqk-WJEAIvBVOdbVzMtL_7KgY3qKFORijVOQ7is3IHRyKVjaBuAn1cw&signatureversion=3&expires=2023-10-16T17%3A18%3A42%2B0330&response=json&signature=n3EvTVy0p64heEc%3D

response :

{"listtemplatesresponse":{"count":8,"template":[{"id":"e82e822c-7bf3-4583-99d8-eed1d8424f28","name":"Ubuntu 16.04","displaytext":"Ubuntu 16.04","ispublic":true,"created":"2018-07-04T18:46:49+0430","isready":true,"passwordenabled":true,"format":"OVA","isfeatured":true,"crossZones":false,"ostypeid":"3785e498-8be6-11e7-90f0-005056a86dbb","ostypename":"Ubuntu 16.04 (64-bit)","account":"","zoneid":"-fa65-4a30loh0b0-67fba098cc5c","zonename":"jfljfk","size":42949672960,"physicalsize":1928637952,"templatetype":"USER","hypervisor":"VMware","domain":"ROOT","domainid":"68c392a86djio","isextractable":false,"sourcetemplateid":"9b1b9489-837b-47b3-8453-8c4df12c7e25","details":{"dataDiskController":"lsisas1068","nicAdapter":"Vmxnet3","username":"root","rootDiskController":"lsisas1068"},"downloaddetails":[{"downloadState":"DOWNLOADED","datastore":"AF-CLD-SCST01","downloadPercent":"100"}],"bits":0,"sshkeyenabled":false,"isdynamicallyscalable":true,"directdownload":false,"deployasis":false,"childtemplates":[],"requireshvm":true,"tags":[],"hasannotations":false},{"id":"e82e822c-7jfdjygflgjhgljgd8-eed1djif","name":"Ubuntu 16.04","displaytext":"Ubuntu 16.04","ispublic":true,"created":"2023-07-30T23:36:08+0330","isready":true,"passwordenabled":true,"format":"OVA","isfeatured":true,"crossZones":false,"ostypeid":"3785e498-8be6-11e7-90f0-005056a86dbb","ostypename":"Ubuntu 16.04 (64-bit)","account":"a.eskandari","size":42949672960,"physicalsize":1928637952,"templatetype":"USER","hypervisor":"VMware","domain":"ROOT","domainid":"65646on925-8be4-11e7-90f0-fkjdwpg","isextractable":false,"sourcetemplateid":"-837b-47b3-8453-8c4df12c7e25","details":{"dataDiskController":"lsisas1068","nicAdapter":"Vmxnet3","username":"root","rootDiskController":"lsisas1068"},"downloaddetails":[{"downloadState":"DOWNLOADED","datastore":"CLD-SCST01","downloadPercent":"100"}],"bits":0,"sshkeyenabled":false,"isdynamicallyscalable":true,"directdownload":false,"deployasis":false,"childtemplates":[],"requireshvm":true,"tags":[],"hasannotations":false}]}}

for some users we got this response for same request : {"listtemplatesresponse":{"uuidList":[],"errorcode":530,"cserrorcode":9999,"errortext":"Internal error executing command, please contact your system administrator"}}

weizhouapache commented 1 year ago

@meisammaleki list templates with the same template id ? can you share the management server logs ?

meisammaleki commented 1 year ago

the template id is not same this is a request : https://0.0.0.0:8443/client/api?templatefilter=featured&id=3b8e915c-b3db-4c83-8e18-7374234e27b1&command=listTemplates&apiKey=k-g2wxG3CCJvD_ClmHBggpTMFGHW3G8Big12XKpk_FyHF1GMDZIQPWA&signatureversion=3&expires=2023-10-17T19%3A46%3A28%2B0330&response=json&signature=bQbX2fky0%2Bw

response : {"listtemplatesresponse":{"uuidList":[],"errorcode":530,"cserrorcode":9999,"errortext":"Internal error executing command, please contact your system administrator"}}

and this is management log :

2023-10-18 08:32:52,820 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50736:ctx-e6c389a6 ctx-6917c1b4 ctx-4cf0415b) (logid:5aee5e37) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:32:54,841 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-51081:ctx-9f590623 ctx-8f769441 ctx-7b99e6db) (logid:3115fc0f) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:32:57,946 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-51111:ctx-e3b8a3be ctx-8df51425 ctx-27f94111) (logid:7035a404) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:02,455 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-129:ctx-44baa4a3) (logid:23f0913f) Unable to find matched VM in CloudStack DB. name: 5ccd99643edc39d5a42fd6c13d1e5044 2023-10-18 08:33:02,583 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-129:ctx-44baa4a3) (logid:23f0913f) Unable to find matched VM in CloudStack DB. name: 1f9304032776362482c74847e5876ef0 2023-10-18 08:33:04,814 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50727:ctx-3d224df6 ctx-f2140848 ctx-9d9dc48b) (logid:aa034742) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:06,484 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-51042:ctx-06bb6548 ctx-a73b1c99 ctx-331eb9bb) (logid:90590ccb) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:09,197 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50933:ctx-4d851bf9 ctx-44415c28 ctx-016931b4) (logid:d16e2c3b) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:09,359 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50602:ctx-a1bb0a87 ctx-121d68db ctx-63dd1fd5) (logid:899a0029) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:09,924 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-257:ctx-f37c8aa1) (logid:9e0dcc9c) Unable to find matched VM in CloudStack DB. name: 63b2f486449f3442bc21424d45ade6c8 2023-10-18 08:33:10,243 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-257:ctx-f37c8aa1) (logid:9e0dcc9c) Unable to find matched VM in CloudStack DB. name: i-11170-4240-VM 2023-10-18 08:33:10,464 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-257:ctx-f37c8aa1) (logid:9e0dcc9c) Unable to find matched VM in CloudStack DB. name: 7ce90ebf9b383f768a80bcc3c6e98367 2023-10-18 08:33:14,784 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50602:ctx-11f72656 ctx-c920c9b0 ctx-22e1b73a) (logid:bd684ea9) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:16,159 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50602:ctx-2b419a14 ctx-b4194835 ctx-0061cc92) (logid:080205d1) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:18,287 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50849:ctx-582da585 ctx-22985dcc ctx-31926f7d) (logid:f3c037a7) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:20,448 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50837:ctx-7032815d ctx-fe8ec65b ctx-9ab6db2e) (logid:0f2a23bb) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:22,984 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-51111:ctx-015b5013 ctx-aa480846 ctx-f261a596) (logid:13f908e7) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:25,899 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50736:ctx-92417309 ctx-5b49d87f ctx-d0f1a3fb) (logid:cd7ef23e) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:27,410 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50933:ctx-c8720fa3 ctx-56b810a1 ctx-61ac9aec) (logid:fab95165) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:30,087 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgentCronJob-258:ctx-aec0f50f) (logid:b2ee7494) Unable to find matched VM in CloudStack DB. name: 5f9d22642c79320087426291a627a612 2023-10-18 08:33:34,394 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50736:ctx-88df85ae ctx-f3a98275 ctx-66bf0605) (logid:f26c480d) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:40,028 ERROR [c.c.a.ApiServer] (qtp1750498848-51111:ctx-838b1325 ctx-7a32cea2 ctx-10977908) (logid:ea0c7e15) unhandled exception executing api command: [Ljava.lang.String;@3cd0feeb java.lang.NullPointerException 2023-10-18 08:33:43,674 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50727:ctx-75dc50d1 ctx-0c33bb04 ctx-2357b3ee) (logid:8e8339f5) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:45,662 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-51111:ctx-4b776ec6 ctx-cb02be56 ctx-fe4644ca) (logid:b5924a39) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:45,820 ERROR [c.c.s.StatsCollector] (StatsCollector-4:ctx-debc473d) (logid:bcd92637) db statistics collection failed due to For input string: "3549504386" 2023-10-18 08:33:45,820 DEBUG [c.c.s.StatsCollector] (StatsCollector-4:ctx-debc473d) (logid:bcd92637) db statistics collection failed. java.lang.NumberFormatException: For input string: "3549504386" at java.base/java.lang.NumberFormatException.forInputString(NumberFormatException.java:65) 2023-10-18 08:33:47,775 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50933:ctx-ab9846a6 ctx-1c67342e ctx-0e4f4f54) (logid:d73a8e8a) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:49,873 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50849:ctx-dbd39a9f ctx-557648d5 ctx-538af41b) (logid:21a967b4) Received unknown parameters for command listStoragePools. Unknown parameters : listall 2023-10-18 08:33:52,186 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50736:ctx-a444d1c3 ctx-d484aafe ctx-32d68115) (logid:1ca94006) Received unknown parameters for command listStoragePools. Unknown parameters : listall c2023-10-18 08:33:57,797 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp1750498848-50727:ctx-246c0321 ctx-2b146f05 ctx-7526427c) (logid:79eab879) Received unknown parameters for command listStoragePools. Unknown parameters : listall

harikrishna-patnala commented 1 year ago

@meisammaleki This log snippet does not seem to have the listtemplates cmd, can you please look for it and share. Also this log snippet does not seem to be good, I see an NPE in apiserver.

DaanHoogland commented 1 year ago

@meisammaleki the title of your issue says listvolume and the contents listtemplates. can you rectify?

meisammaleki commented 1 year ago

@harikrishna-patnala these are logs that show Error on listtemplate api request

===START=== 88.0.0.10 -- GET templatefilter=featured&id=808580a8-19f4-48d6-b099-259b2a99b5d9&command=listTemplates&apiKey=iVSg5LUaMgk_2-h58oD54DEzDxAl3rA_mf2MZ8RwZ57YA&signatureversion=3&expires=2023-10-19T23%3A20%3A52%2B0330&response=json&signature=wSt%2BZ9Pi7vtm3BI8yjimz7FMbEE%3D 2023-10-19 13:20:52,178 DEBUG [c.c.a.ApiServer] (qtp1750498848-68526:ctx-c8cc078a ctx-59ba41ce) (logid:db538ca7) CIDRs from which account 'Acct[513bdbc5-63c2-4e4c-a5b5-dd326f6c79d1-afra-3296-4919] -- Account {"id": 5362, "name": "afra-3296-4919", "uuid": "513bdbc5-63c2-4e4c-a5b5-dd326f6c79d1"}' is allowed to perform API calls: 0.0.0.0/0,::/0 2023-10-19 13:20:52,238 ERROR [c.c.a.ApiServer] (qtp1750498848-68526:ctx-c8cc078a ctx-59ba41ce ctx-d2d266ad) (logid:db538ca7) unhandled exception executing api command: [Ljava.lang.String;@46aac324 java.lang.NullPointerException 2023-10-19 13:20:52,242 DEBUG [c.c.a.ApiServlet] (qtp1750498848-68526:ctx-c8cc078a ctx-59ba41ce ctx-d2d266ad) (logid:db538ca7) ===END===

meisammaleki commented 1 year ago

@meisammaleki the title of your issue says listvolume and the contents listtemplates. can you rectify? tnx I change the issue name

weizhouapache commented 1 year ago

@harikrishna-patnala these are logs that show Error on listtemplate api request

===START=== 88.0.0.10 -- GET templatefilter=featured&id=808580a8-19f4-48d6-b099-259b2a99b5d9&command=listTemplates&apiKey=iVSg5LUaMgk_2-h58oD54DEzDxAl3rA_mf2MZ8RwZ57YA&signatureversion=3&expires=2023-10-19T23%3A20%3A52%2B0330&response=json&signature=wSt%2BZ9Pi7vtm3BI8yjimz7FMbEE%3D 2023-10-19 13:20:52,178 DEBUG [c.c.a.ApiServer] (qtp1750498848-68526:ctx-c8cc078a ctx-59ba41ce) (logid:db538ca7) CIDRs from which account 'Acct[513bdbc5-63c2-4e4c-a5b5-dd326f6c79d1-afra-3296-4919] -- Account {"id": 5362, "name": "afra-3296-4919", "uuid": "513bdbc5-63c2-4e4c-a5b5-dd326f6c79d1"}' is allowed to perform API calls: 0.0.0.0/0,::/0 2023-10-19 13:20:52,238 ERROR [c.c.a.ApiServer] (qtp1750498848-68526:ctx-c8cc078a ctx-59ba41ce ctx-d2d266ad) (logid:db538ca7) unhandled exception executing api command: [Ljava.lang.String;@46aac324 java.lang.NullPointerException 2023-10-19 13:20:52,242 DEBUG [c.c.a.ApiServlet] (qtp1750498848-68526:ctx-c8cc078a ctx-59ba41ce ctx-d2d266ad) (logid:db538ca7) ===END===

@meisammaleki Can you share the logs after this?

2023-10-19 13:20:52,238 ERROR [c.c.a.ApiServer] (qtp1750498848-68526:ctx-c8cc078a ctx-59ba41ce ctx-d2d266ad) (logid:db538ca7) unhandled exception executing api command: [Ljava.lang.String;@46aac324
java.lang.NullPointerException
meisammaleki commented 1 year ago

Hello again, I suppose these pictures show why I got error on API request from whmcs side. I get 404 not found error when I try to see the Template on ACS for instance 4919. I have checked for other users too with same template and it was ok.

this is log on ACS management when I try to check template on UI : 2023-10-20 08:28:08,086 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917360:ctx-82ba6320) (logid:30abfa06) ===START=== 192.168.123.108 -- GET resourceids=808580a8-19f4-48d6-b099-259b2a99b5d9&resourcetype=template&command=listResourceIcon&response=json 2023-10-20 08:28:08,090 DEBUG [c.c.a.ApiServlet] (qtp1750498848-918173:ctx-d8210763) (logid:72c5cf20) ===START=== 192.168.123.108 -- GET listall=true&templatefilter=all&id=808580a8-19f4-48d6-b099-259b2a99b5d9&page=1&pagesize=20&showIcon=true&command=listTemplates&response=json 2023-10-20 08:28:08,131 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917360:ctx-82ba6320 ctx-529794b7) (logid:30abfa06) ===END=== 192.168.123.108 -- GET resourceids=808580a8-19f4-48d6-b099-259b2a99b5d9&resourcetype=template&command=listResourceIcon&response=json 2023-10-20 08:28:08,163 DEBUG [c.c.a.ApiServlet] (qtp1750498848-918173:ctx-d8210763 ctx-29e1ecd6) (logid:72c5cf20) ===END=== 192.168.123.108 -- GET listall=true&templatefilter=all&id=808580a8-19f4-48d6-b099-259b2a99b5d9&page=1&pagesize=20&showIcon=true&command=listTemplates&response=json 2023-10-20 08:28:22,230 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917939:ctx-11ef3c72) (logid:cca236e0) ===START=== 192.168.123.108 -- GET username=m.maleki&listall=true&command=listUsers&response=json 2023-10-20 08:28:22,238 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917772:ctx-5ea9d46b) (logid:288a818b) ===START=== 192.168.123.108 -- GET command=listCapabilities&response=json 2023-10-20 08:28:22,241 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917360:ctx-85914487) (logid:b43ccc9c) ===START=== 192.168.123.108 -- GET username=m.maleki&command=listUsers&response=json 2023-10-20 08:28:22,288 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917131:ctx-f12f8c93) (logid:379dac99) ===START=== 192.168.123.108 -- GET command=listLdapConfigurations&response=json 2023-10-20 08:28:22,294 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917360:ctx-85914487 ctx-36d696c5) (logid:b43ccc9c) ===END=== 192.168.123.108 -- GET username=m.maleki&command=listUsers&response=json 2023-10-20 08:28:22,313 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917772:ctx-5ea9d46b ctx-31061e6e) (logid:288a818b) ===END=== 192.168.123.108 -- GET command=listCapabilities&response=json 2023-10-20 08:28:22,317 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917772:ctx-d5f80ace) (logid:2391d220) ===START=== 192.168.123.108 -- GET command=cloudianIsEnabled&response=json 2023-10-20 08:28:22,338 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917131:ctx-f12f8c93 ctx-b372302f) (logid:379dac99) ===END=== 192.168.123.108 -- GET command=listLdapConfigurations&response=json 2023-10-20 08:28:22,373 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917772:ctx-d5f80ace ctx-8c9c3cb7) (logid:2391d220) ===END=== 192.168.123.108 -- GET command=cloudianIsEnabled&response=json 2023-10-20 08:28:22,540 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917939:ctx-11ef3c72 ctx-00f485fd) (logid:cca236e0) ===END=== 192.168.123.108 -- GET username=m.maleki&listall=true&command=listUsers&response=json 2023-10-20 08:28:23,403 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917772:ctx-71cafd00) (logid:fb6b9fc8) ===START=== 192.168.123.108 -- GET listAll=true&details=min&page=1&pageSize=500&command=listAndSwitchSamlAccount&response=json 2023-10-20 08:28:23,405 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917194:ctx-e93589d3) (logid:5cf000da) ===START=== 192.168.123.108 -- GET listAll=true&details=min&page=1&pageSize=500&showIcon=true&command=listProjects&response=json 2023-10-20 08:28:23,408 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917939:ctx-98e13b70) (logid:ee125f2c) ===START=== 192.168.123.108 -- GET id=6d784d7e-81e5-453b-9b46-b92418970183&showicon=true&command=listUsers&response=json 2023-10-20 08:28:23,428 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917772:ctx-71cafd00 ctx-aa4369fe) (logid:fb6b9fc8) ===END=== 192.168.123.108 -- GET listAll=true&details=min&page=1&pageSize=500&command=listAndSwitchSamlAccount&response=json 2023-10-20 08:28:23,437 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917194:ctx-e93589d3 ctx-a8a97802) (logid:5cf000da) ===END=== 192.168.123.108 -- GET listAll=true&details=min&page=1&pageSize=500&showIcon=true&command=listProjects&response=json 2023-10-20 08:28:23,453 DEBUG [c.c.a.ApiServlet] (qtp1750498848-917939:ctx-98e13b70 ctx-2762b675) (logid:ee125f2c) ===END=== 192.168.123.108 -- GET id=6d784d7e-81e5-453b-9b46-b92418970183&showicon=true&command=listUsers&response=json

meisammaleki commented 1 year ago

A B

shwstppr commented 1 year ago

@meisammaleki thank you for the updates but logs are not showing complete detail about the exception. Are you running multiple management servers? If so can you please check and share logs from them? Also, any idea if were there any changes to the template or storage or the owner account after which you started seeing this issue?

meisammaleki commented 1 year ago

Yes we have multi management , I sent an exception error logs on previous comment. I will try to find more logs on management servers.

meisammaleki commented 1 year ago

Hello @shwstppr I got unhandled exception executing api command: [Ljava.lang.String;@713482cd on both management servers log :

mgmt01 : tail -f /var/log/cloudstack/management/management-server.log |grep -i -E 'Error' 2023-10-22 11:16:50,006 ERROR [c.c.a.ApiServer] (qtp1750498848-116145:ctx-e5f8c3c5 ctx-806f1f24 ctx-27e49d7a) (logid:87c2376b) unhandled exception executing api command: [Ljava.lang.String;@1dd9387d 2023-10-22 11:16:52,292 ERROR [c.c.s.StatsCollector] (StatsCollector-2:ctx-58fe19b9) (logid:e36b0798) db statistics collection failed due to For input string: "4204758791" 2023-10-22 11:17:10,346 ERROR [c.c.a.ApiServer] (qtp1750498848-116061:ctx-3c16fe2f ctx-41611ac5 ctx-77af7e3c) (logid:dadd9d69) unhandled exception executing api command: [Ljava.lang.String;@ad6941c 2023-10-22 11:17:12,968 ERROR [c.c.a.ApiServer] (qtp1750498848-116220:ctx-18c83ca3 ctx-2e5e3619 ctx-9581f4e8) (logid:1e22126d) unhandled exception executing api command: [Ljava.lang.String;@3a0741fe

mgmt02 :

tail -f /var/log/cloudstack/management/management-server.log |grep -i -E 'Error' 2023-10-22 11:16:23,882 ERROR [c.c.s.StatsCollector] (StatsCollector-2:ctx-ae192586) (logid:2799bf30) db statistics collection failed due to For input string: "4204710816" 2023-10-22 11:16:47,605 ERROR [c.c.a.ApiServer] (qtp1750498848-982147:ctx-3fa6834e ctx-c0219b9d ctx-2d104d0b) (logid:1c7159ba) unhandled exception executing api command: [Ljava.lang.String;@713482cd

weizhouapache commented 1 year ago

@meisammaleki Can you share the lines after these logs? They will tell us which line of code caused the issue.

2023-10-22 11:17:10,346 ERROR [c.c.a.ApiServer] (qtp1750498848-116061:ctx-3c16fe2f ctx-41611ac5 ctx-77af7e3c) (logid:dadd9d69) unhandled exception executing api command: [Ljava.lang.String;@ad6941c 2023-10-22 11:17:12,968 ERROR [c.c.a.ApiServer] (qtp1750498848-116220:ctx-18c83ca3 ctx-2e5e3619 ctx-9581f4e8) (logid:1e22126d) unhandled exception executing api command: [Ljava.lang.String;@3a0741fe

meisammaleki commented 1 year ago

@weizhouapache these are logs after JavaLang exeption error on management 2 :

===START=== 80.x.x.x -- GET templatefilter=featured&id=3b8e915c-b3db-4c83-8e18-7374234e27b1&command=listTemplates&apiKey=kWgDqLnkoSBs9AkDKEouHD_ClmHBggpTMFGHW3G8Big12XKpk_FyHF1GMDZIQPWA&signatureversion=3&expires=2023-10-22T21%3A19%3A25%2B0330&response=json&signature=1jCCA1Q0nRmxZh4LLvFTIqs%2F7ek%3D 2023-10-22 11:16:47,582 DEBUG [c.c.a.ApiServer] (qtp1750498848-982147:ctx-3fa6834e ctx-c0219b9d) (logid:1c7159ba) CIDRs from which account 'Acct[c7794b81-6316-485b-975d-1e852fff6434-afra-3057-4499] -- Account {"id": 4354, "name": "afra-3057-4499", "uuid": "c7794b81-6316-485b-975d-1e852fff6434"}' is allowed to perform API calls: 0.0.0.0/0,::/0

2023-10-22 11:16:47,605 ERROR [c.c.a.ApiServer] (qtp1750498848-982147:ctx-3fa6834e ctx-c0219b9d ctx-2d104d0b) (logid:1c7159ba) unhandled exception executing api command: [Ljava.lang.String;@713482cd java.lang.NullPointerException

2023-10-22 11:16:47,610 DEBUG [c.c.a.ApiServlet] (qtp1750498848-982147:ctx-3fa6834e ctx-c0219b9d ctx-2d104d0b) (logid:1c7159ba) ===END=== 80.x.x.x -- GET templatefilter=featured&id=3b8e915c-b3db-4c83-8e18-7374234e27b1&command=listTemplates&apiKey=k-g2wxG3CCJvNvd9izzlsJjWgDqLnkoSBs9AkDKEouHD_ClmHBggpTMFGHW3G8Big12XKpk_FyHF1GMDZIQPWA&signatureversion=3&expires=2023-10-22T21%3A19%3A25%2B0330&response=json&signature=1jCCA1Q0nRmxZh4LLvFTIqs%2F7ek%3D 2023-10-22 11:16:47,628 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) find VM i-27212-9708-afra-11586-18330 on host 2023-10-22 11:16:47,628 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) VM i-27212-9708-afra-11586-18330 found in host cache 2023-10-22 11:16:47,645 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) find VM i-18412-6724-VM on host 2023-10-22 11:16:47,645 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) VM i-18412-6724-VM found in host cache 2023-10-22 11:16:47,663 DEBUG [c.c.h.v.r.VmwareResource] (DirectAgent-466:ctx-e62b612c af-cld-host19.afracloud.local, cmd: GetStorageStatsCommand) (logid:9190714d) Datastore summary info: [storageId: 47da28b9-5830-3099-b2dd-a28f54830259, ], localPath: /AfraCloud01/8K1-MIX-POOL-CLD_27, poolType: VMFS, capacity: (4.8826 TB) 5368440684544, free: (1.2116 TB) 1332148699136, used: (3.6710 TB) 4036291985408]. 2023-10-22 11:16:47,664 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-466:ctx-e62b612c) (logid:9190714d) Seq 193-2382967152832451171: Response Received: 2023-10-22 11:16:47,664 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) find VM i-22645-8137-VM on host 2023-10-22 11:16:47,664 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) VM i-22645-8137-VM found in host cache 2023-10-22 11:16:47,664 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (DirectAgent-466:ctx-e62b612c) (logid:9190714d) Seq 193-2382967152832451171: MgmtId 345050440849: Resp: Routing to peer 2023-10-22 11:16:47,679 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) find VM i-11956-4512-VM on host 2023-10-22 11:16:47,680 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) VM i-11956-4512-VM found in host cache 2023-10-22 11:16:47,680 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-476:ctx-84c4a58d) (logid:247e2f37) Seq 148-8136597151774954955: Executing request 2023-10-22 11:16:47,680 DEBUG [c.c.h.v.r.VmwareResource] (DirectAgent-476:ctx-84c4a58d) (logid:9190714d) Executing resource command GetStorageStatsCommand: []. 2023-10-22 11:16:47,696 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) find VM i-27491-9802-afra-4561-18579 on host 2023-10-22 11:16:47,696 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) VM i-27491-9802-afra-4561-18579 found in host cache 2023-10-22 11:16:47,747 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) find VM i-24217-8674-VM on host 2023-10-22 11:16:47,747 DEBUG [c.c.h.v.m.HostMO] (DirectAgent-455:ctx-4ffa4313 af-cld-host16.afracloud.local, cmd: GetVmStatsCommand) (logid:e313732f) VM i-24217-8674-VM found in host cache 2023-10-22 11:16:47,759 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-127:ctx-6071634b) (logid:06996657) Seq 214-3925450025206840542: Executing request 2023-10-22 11:16:47,760 DEBUG [c.c.h.v.r.VmwareResource] (DirectAgent-127:ctx-6071634b) (logid:635e2012) Executing resource command GetHostStatsCommand: [].

DaanHoogland commented 1 year ago

this sounds suspiciously like #8127 (though that issue is not present on 4.17, and that one is about guest OSses) worth looking into.

shwstppr commented 1 year ago

@meisammaleki Unfortunately we are not getting stacktrace of NullPointerException here from the logs. If it is just one template which is causing API failure can you please share output of the following SQL query if that could give a hint, select * from template_view where name='Windows server 2019' OR display_text='Windows server 2019'\G

meisammaleki commented 1 year ago

@shwstppr query result atached query result.txt

shwstppr commented 1 year ago

@meisammaleki Did a quick check on your query results. As there are multiple template entries can you please confirm if your problematic template is having uuid = 808580a8-19f4-48d6-b099-259b2a99b5d9?

meisammaleki commented 1 year ago

@shwstppr exatly and also another template with different uuid, these template state are inactive and removed status is not Null. Both of them have removed at the same time! What should we do now? I can change removed value to Null and state to Active. But I am not sure it will work or not

DaanHoogland commented 1 year ago

@meisammaleki , if you are sure you can set the state to Destroyed as well (instead of making them active)

meisammaleki commented 1 year ago

@DaanHoogland I am not sure about changing state from Inactive to Destroyed because some instances using this template. as I said before customer from WHMCS login on their service management panel to do some activities like "reboot, change password and etc " . So when users who have created their instances using this templates are going to login to their panel (on whmcs) getting error.

DaanHoogland commented 1 year ago

2023-10-22 11:16:52,292 ERROR [c.c.s.StatsCollector] (StatsCollector-2:ctx-58fe19b9) (logid:e36b0798) db statistics collection failed due to For input string: "4204758791"

These are fixed in 4.18 and not really a problem. an int is parsed for a very long value. The StatsCollector is not involved in listTemplates.

@DaanHoogland I am not sure about changing state from Inactive to Destroyed because some instances using this template. as I said before customer from WHMCS login on their service management panel to do some activities like "reboot, change password and etc " . So when users who have created their instances using this templates are going to login to their panel (on whmcs) getting error.

ok fair enough.

Did you check the templates are available on the primary store pools and referenced as such in the DB? table template_spool_ref

meisammaleki commented 1 year ago

Finally we solved the problem by changing VM template id in vm_instance table. We replace the removed template id with a template id that it was Active

DaanHoogland commented 1 year ago

Finally we solved the problem by changing VM template id in vm_instance table. We replace the removed template id with a template id that it was Active

nice that it is solved, but do we now know what caused it?

would be nice for future generation ;)

DaanHoogland commented 10 months ago

closing as per https://github.com/apache/cloudstack/issues/8111#issuecomment-1785460236