API tools faq
paste
Advertisement
NMamaev

Untitled

NMamaev
Nov 23rd, 2023
96
0
Never
Add comment
Not a member of Pastebin yet? Sign Up, it unlocks many cool features!
Bash 103.44 KB | None | 0 0
raw download clone embed print report
  1. root@42c85b6ce222:/var/log# grep ecca388e597bb9313f07e86242a51874 *.log*
  2. connect_storages.log:2023-11-21 11:38:23.189 [pid=10707] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [manager] [execute_request] Try connect to http://input:1500/vm/v3/node/2 with headers {'instance-id': '1', 'internal-auth': 'on'}
  3. connect_storages.log:2023-11-21 11:38:23.191 [pid=10707] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [connectionpool] [_new_conn] Starting new HTTP connection (1): input:1500
  4. connect_storages.log:2023-11-21 11:38:23.197 [pid=10707] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [connectionpool] [_make_request] http://input:1500 "GET /vm/v3/node/2 HTTP/1.1" 200 1572
  5. connect_storages.log:2023-11-21 11:38:23.198 [pid=10707] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [manager] [execute_request] Try connect to http://input:1500/vm/v3/node/2 with headers {'instance-id': '1', 'internal-auth': 'on'}
  6. connect_storages.log:2023-11-21 11:38:23.199 [pid=10707] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [connectionpool] [_new_conn] Starting new HTTP connection (1): input:1500
  7. connect_storages.log:2023-11-21 11:38:23.202 [pid=10707] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [connectionpool] [_make_request] http://input:1500 "GET /vm/v3/node/2 HTTP/1.1" 200 1572
  8. node_network.log:2023-11-21 11:38:14.398 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [node_network_astra_1.7] [main] node network configure
  9. node_network.log:2023-11-21 11:38:14.399 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [node_network_astra_1.7] [main] astra node network with params: {
  10. node_network.log:2023-11-21 11:38:14.400 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [from_json] ssh params: {'ssh_address': '172.31.36.17', 'ssh_port': 22, 'ssh_user': 'astra-node2'}
  11. node_network.log:2023-11-21 11:38:14.403 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connecting to astra-node2@172.31.36.17:22
  12. node_network.log:2023-11-21 11:38:14.470 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connection to astra-node2@172.31.36.17:22 established
  13. node_network.log:2023-11-21 11:38:14.470 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [run] run ip route get 1 | awk '{print $5;exit}'
  14. node_network.log:2023-11-21 11:38:14.540 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [run] run cat /proc/net/route | grep eth0
  15. node_network.log:2023-11-21 11:38:14.597 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [run] run ping -w 10 -c 3 -q 172.31.36.1
  16. node_network.log:2023-11-21 11:38:16.714 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connecting to astra-node2@172.31.36.17:22
  17. node_network.log:2023-11-21 11:38:16.781 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connection to astra-node2@172.31.36.17:22 established
  18. node_network.log:2023-11-21 11:38:16.781 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [run] run systemctl is-active NetworkManager
  19. node_network.log:2023-11-21 11:38:16.874 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connecting to astra-node2@172.31.36.17:22
  20. node_network.log:2023-11-21 11:38:16.942 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connection to astra-node2@172.31.36.17:22 established
  21. node_network.log:2023-11-21 11:38:16.942 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [run] run test -d /opt/ispsystem/vm/node_network_configure
  22. node_network.log:2023-11-21 11:38:17.018 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connecting to astra-node2@172.31.36.17:22
  23. node_network.log:2023-11-21 11:38:17.130 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connection to astra-node2@172.31.36.17:22 established
  24. node_network.log:2023-11-21 11:38:17.166 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connecting to astra-node2@172.31.36.17:22
  25. node_network.log:2023-11-21 11:38:17.239 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connection to astra-node2@172.31.36.17:22 established
  26. node_network.log:2023-11-21 11:38:17.240 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [run] run test -f /opt/ispsystem/vm/node_network_configure/result_file
  27. node_network.log:2023-11-21 11:38:17.322 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [configure] [run_script] Run configure script cmd: cd /opt/ispsystem/vm/node_network_configure && python3 2023-11-21-23-38-17_configure.py with input_params: {"gateway": "172.31.36.1", "script_result_file": "/opt/ispsystem/vm/node_network_configure/result_file", "workdir": "/opt/ispsystem/vm/node_network_configure", "required_ifaces": ["eth0"]}
  28. node_network.log:2023-11-21 11:38:17.334 [pid=10698] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connecting to astra-node2@172.31.36.17:22
  29. node_network.log:2023-11-21 11:38:17.413 [pid=10698] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [connect] [vm_security] Connection to astra-node2@172.31.36.17:22 established
  30. node_network.log:2023-11-21 11:38:17.413 [pid=10698] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [run] run cd /opt/ispsystem/vm/node_network_configure && python3 2023-11-21-23-38-17_configure.py
  31. node_network.log:2023-11-21 11:38:22.131 [pid=10698] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [remote] [run] cd /opt/ispsystem/vm/node_network_configure && python3 2023-11-21-23-38-17_configure.py failed with code 2 stderr ""
  32. node_network.log:2023-11-21 11:38:22.133 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [configure] [run_script] failed to configure network, changes have been reverted
  33. node_network.log:2023-11-21 11:38:22.133 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [configure] [debian_configure] Network import failed: {'started': True, 'error': 'failed to configure network, changes have been reverted', 'reverted': True}
  34. node_network.log:2023-11-21 11:38:22.134 [pid=10678] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [node_network_astra_1.7] [main] Network configure result: {'started': True, 'error': 'failed to configure network, changes have been reverted', 'reverted': True}
  35. vm_1_reader.log:2023-11-23 00:34:29.121 [pid=385] [#ee0b2f92b10b638958e8f6dd90055376/10.60.4.173/@n.mamaev@ispsystem.com] Response body '{"last_notify":875,"task":{"account":{"email":"n.mamaev@ispsystem.com","id":"100000","ip":"127.0.0.1"},"date_create":"2023-11-21T23:36:55.795544","date_end":"2023-11-21T23:38:22","date_start":"2023-11-21T23:36:55","message_params":{"ip_addr":"172.31.36.17","name":"node2"},"name":"node_create","output":"Unhandled exception: failed to parse script output: '{\"started\": true, \"error\": \"failed to configure network, changes have been reverted\", \"reverted\": true}{\"started\": true, \"error\": \"failed to configure network, changes have been reverted\", \"reverted\": true}'","param":["--action","node_create","--virt-type","kvm","--log-name","node_create/node_2","--params","{\"autorun_scripts\":[],\"changed\":[],\"cluster_id\":1,\"datacenter_type\":\"common\",\"deleted\":[],\"gateway\":null,\"id\":2,\"iface_list\":[{\"id\":2,\"name\":\"eth0\",\"nm_ruled\":null,\"state\":\"changed\",\"type\":\"eth\"},{\"id\":2,\"name\":\"vmbr0\",\"nm_ruled\":null,\"state\":\"new\",\"type\":\"bridge\"}],\"image_storage_path\":\"/image\",\"ip\":\"172.31.36.17\",\"network_autosetup_disabled\":false,\"new\":[{\"gateway_v4\":\"172.31.36.1\",\"gateway_v6\":null,\"id\":2,\"ipv4\":[\"172.31.36.17/23\"],\"ipv6\":[],\"name\":\"vmbr0\",\"old_slaves\":[],\"old_take_slave_ip\":null,\"old_vlan\":null,\"slaves\":[{\"id\":2,\"name\":\"eth0\",\"type\":\"eth\"}],\"take_slave_ip\":true,\"type\":\"bridge\",\"vlan\":null}],\"nm_ruled\":false,\"node\":{\"connection\":\"eyJzc2hfYWRkcmVzcyI6IjE3Mi4zMS4zNi4xNyIsInNzaF9wb3J0IjoyMiwic3NoX3VzZXIiOiJhc3RyYS1ub2RlMiJ9\"},\"node_addr_v6\":null,\"node_interface_name\":\"eth0\",\"os_major_version\":\"1.7\",\"os_name\":\"astra\",\"os_storage_path\":\"/share\",\"os_version\":\"Astra Linux 1.7_x86-64\",\"proxy_enabled\":false,\"spice_enabled\":true,\"ssh_port\":22,\"ssh_user\":\"astra-node2\",\"timeout\":300,\"timezone\":\"UTC\"}"],"request_id":"ecca388e597bb9313f07e86242a51874","status":"failed"}}'
  36. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] request method: POST url: /node version: HTTP/1.1
  37. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Handler 'node' choosen
  38. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [connection]close
  39. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [content-length]254
  40. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [host]localhost
  41. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [instance-id]1
  42. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [internal-auth]eyJsYW5nIjoicnUiLCJvd25lcl9lbWFpbCI6Im4ubWFtYWV2QGlzcHN5c3RlbS5jb20iLCJvd25lcl9pZCI6MTAwMDAwLCJyb2xlcyI6WyJAYWRtaW4iXSwic2Vzc2lvbiI6IjEwMDAwMDAwLWU5Nzk2MGYzLTUyMGQtNGUzNy1iMDgxLThiNzYzN2E4OTFjZCIsInRydXN0ZWVfZW1haWwiOiJuLm1hbWFldkBpc3BzeXN0ZW0uY29tIiwidHJ1c3RlZV9pZCI6MTAwMDAwLCJ4c3JmX3Rva2VuIjoiMTAwMDAwMDAtZTk3OTYwZjMtNTIwZC00ZTM3LWIwODEtOGI3NjM3YTg5MWNkIn0=
  43. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-forwarded-for]127.0.0.1
  44. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-remote-ip]127.0.0.1
  45. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-request-id]ecca388e597bb9313f07e86242a51874
  46. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-xsrf-token]10000000-e97960f3-520d-4e37-b081-8b7637a891cd
  47. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] RequestBody: {"cluster":1,"comment":"","host_filter":[],"host_limit":-1,"host_max":null,"ip":"172.31.36.17","lvm_vg_rename":false,"name":"node2","network_autosetup_disabled":false,"overselling":1,"password":"*","ssh_port":22,"ssh_user":"astra-node2","vcpu_limit":-1}
  48. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] End of POST request
  49. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Invoke POST request callback
  50. vm_1_writer.log:2023-11-21 23:36:54.356 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] WriterAsyncProcess
  51. vm_1_writer.log:2023-11-21 23:36:54.374 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "balancer_config","balancer_mode","vm5_data","spice_enabled","node_os_family","vxlan_mode","node_network_gateway","node_network_timeout","ha_error","ha_cluster_id","ha_agent_version","ha_checking_host","ha_enabled","net_bandwidth_mbitps","dns_servers","host_per_node_limit","proxy_enabled","domain_change_allowed","manage_disk_enabled","iso_enabled","cpu_overselling","overselling","qemu_version","domain_template","image_storage_path","os_storage_path","interface_count","imported_from","host_filter","host_distribution_policy","datacenter_type","virtualization_type","time_zone","comment","name","id" FROM vm_cluster WHERE "id"='1'' duration=814
  52. vm_1_writer.log:2023-11-21 23:36:54.375 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT vm_storage2cluster.id AS id FROM vm_storage2cluster WHERE (vm_storage2cluster.cluster='1')' duration=459
  53. vm_1_writer.log:2023-11-21 23:36:54.376 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 7644
  54. vm_1_writer.log:2023-11-21 23:36:54.376 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7644. Execute command: 'ssh-keygen -R 172.31.36.17 '
  55. vm_1_writer.log:2023-11-21 23:36:54.380 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7644. Finished successefully with status 0
  56. vm_1_writer.log:2023-11-21 23:36:54.380 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7644. Output:
  57. vm_1_writer.log:2023-11-21 23:36:54.380 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7644. Error:
  58. vm_1_writer.log:2023-11-21 23:36:54.381 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 7645
  59. vm_1_writer.log:2023-11-21 23:36:54.381 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7645. Execute command: 'scripts/kvm/node_info.py --private-key /opt/ispsystem/vm/etc/.ssh/vmmgr.1 --host 172.31.36.17 --port 22 --user astra-node2 '
  60. vm_1_writer.log:2023-11-21 23:36:55.441 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7645. Finished successefully with status 0
  61. vm_1_writer.log:2023-11-21 23:36:55.442 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7645. Output: {"os": {"version": "Astra Linux 1.7_x86-64", "name": "astra", "major_version": "1.7"}, "kvm_support": true, "kvm_enabled": true, "cpu_core_count": 4, "mem_mib": 3925, "hostname": "astra-node2", "iface": "eth0"}
  62. vm_1_writer.log:2023-11-21 23:36:55.442 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7645. Error:
  63. vm_1_writer.log:2023-11-21 23:36:55.442 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Node Info: 0
  64. vm_1_writer.log:2023-11-21 23:36:55.442 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Node Info: {"cpu_core_count":4,"hostname":"astra-node2","iface":"eth0","kvm_enabled":true,"kvm_support":true,"mem_mib":3925,"os":{"major_version":"1.7","name":"astra","version":"Astra Linux 1.7_x86-64"}}
  65. vm_1_writer.log:2023-11-21 23:36:55.443 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT name FROM vm_node WHERE hostname='astra-node2' AND cluster='1' LIMIT 1' duration=1194
  66. vm_1_writer.log:2023-11-21 23:36:55.443 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalCall service: checker path: get_info
  67. vm_1_writer.log:2023-11-21 23:36:55.557 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got node_network: [
  68. vm_1_writer.log:2023-11-21 23:36:55.557 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] CheckLicense
  69. vm_1_writer.log:2023-11-21 23:36:55.581 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id, cpu_number, additional_data FROM vm_node' duration=346
  70. vm_1_writer.log:2023-11-21 23:36:55.582 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT COUNT(id) FROM vm_node WHERE cluster = '1'' duration=476
  71. vm_1_writer.log:2023-11-21 23:36:55.583 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id FROM vm_node WHERE name = 'node2' LIMIT 1' duration=140
  72. vm_1_writer.log:2023-11-21 23:36:55.583 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id FROM vm_node WHERE ip_addr = '172.31.36.17' LIMIT 1' duration=160
  73. vm_1_writer.log:2023-11-21 23:36:55.674 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_node ("id","name","comment","cluster","ram_mib","max_vcpu_number","cpu_number","ip_addr","vnc_addr","ssh_port","ssh_user","state","mon_install_date","os_version","overselling","hostname","host_filter") VALUES(2,'node2','',1,3925,4,4,'172.31.36.17','172.31.36.17',22,'astra-node2','prepare_node','2023-11-21 23:36:55','Astra Linux 1.7_x86-64',1.000000,'astra-node2','[]')' duration=90925
  74. vm_1_writer.log:2023-11-21 23:36:55.676 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT MAX(create_time) FROM vm_node_history WHERE event_type='field:state' AND ref='2'' duration=212
  75. vm_1_writer.log:2023-11-21 23:36:55.676 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_node_history (id,event_type,event_info,request_user,request_owner,request_ip,request_id,ref) VALUES (4,'field:state','{"new_value":"prepare_node","old_value":null}','n.mamaev@ispsystem.com','---','127.0.0.1','ecca388e597bb9313f07e86242a51874',2)' duration=518
  76. vm_1_writer.log:2023-11-21 23:36:55.676 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Adding interface: eth0
  77. vm_1_writer.log:2023-11-21 23:36:55.677 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_node_interfaces ("id","name","node","ipv4","gateway_v4","state") VALUES(2,'eth0',2,'172.31.36.17/23','172.31.36.1','enabled')' duration=330
  78. vm_1_writer.log:2023-11-21 23:36:55.677 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Adding relation for: eth0
  79. vm_1_writer.log:2023-11-21 23:36:55.678 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "nm_ruled","date_create","old_values","take_slave_ip","vlan","is_main_network","is_default","state","gateway_v6","gateway_v4","ipv6","ipv4","node","name","id" FROM vm_node_bridge WHERE "name"='eth0' AND "node"='2'' duration=338
  80. vm_1_writer.log:2023-11-21 23:36:55.678 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "nm_ruled","date_create","take_slave_ip","slave_ip","old_values","mode","state","gateway_v6","gateway_v4","ipv6","ipv4","node","name","id" FROM vm_node_bond WHERE "name"='eth0' AND "node"='2'' duration=235
  81. vm_1_writer.log:2023-11-21 23:36:55.678 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "nm_ruled","date_create","old_values","take_slave_ip","vlan","is_main_network","is_default","state","gateway_v6","gateway_v4","ipv6","ipv4","node","name","id" FROM vm_node_bridge WHERE "name"='vmbr0' AND "node"='2'' duration=128
  82. vm_1_writer.log:2023-11-21 23:36:55.679 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='UPDATE vm_node_interfaces SET "ipv4"=NULL,"gateway_v4"=NULL,"state"='changed',"old_values"='{"ip_params":{"gateway_v4":"172.31.36.1","gateway_v6":null,"v4":"172.31.36.17/23","v6":null},"state":"enabled"}' WHERE "id"=2' duration=244
  83. vm_1_writer.log:2023-11-21 23:36:55.679 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "nm_ruled","date_create","old_values","take_slave_ip","vlan","is_main_network","is_default","state","gateway_v6","gateway_v4","ipv6","ipv4","node","name","id" FROM vm_node_bridge WHERE vm_node_bridge.is_default AND vm_node_bridge.is_main_network='1' AND vm_node_bridge.node='2'' duration=180
  84. vm_1_writer.log:2023-11-21 23:36:55.679 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_node_bridge ("id","name","node","ipv4","gateway_v4","state","is_default","take_slave_ip","nm_ruled") VALUES(2,'vmbr0',2,'172.31.36.17/23','172.31.36.1','new','1','1','1')' duration=398
  85. vm_1_writer.log:2023-11-21 23:36:55.680 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "bridge","bond","iface","id" FROM vm_iface2bond2bridge WHERE bridge=2' duration=266
  86. vm_1_writer.log:2023-11-21 23:36:55.680 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT COUNT(*) FROM vm_iface2bond2bridge JOIN vm_node_bridge ON vm_node_bridge.vlan IS NULL AND vm_node_bridge.id = vm_iface2bond2bridge.bridge WHERE (vm_iface2bond2bridge.iface = '2')' duration=255
  87. vm_1_writer.log:2023-11-21 23:36:55.681 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_iface2bond2bridge ("id","iface","bridge") VALUES(2,2,2)' duration=362
  88. vm_1_writer.log:2023-11-21 23:36:55.774 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='UPDATE vm_node SET "network_settings_lock"='1' WHERE "id"=2' duration=93548
  89. vm_1_writer.log:2023-11-21 23:36:55.775 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id, name, state FROM vm_node_interfaces WHERE node='2'' duration=351
  90. vm_1_writer.log:2023-11-21 23:36:55.775 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id, name, state FROM vm_node_bond WHERE node='2'' duration=309
  91. vm_1_writer.log:2023-11-21 23:36:55.775 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id, name, state FROM vm_node_bridge WHERE node='2'' duration=160
  92. vm_1_writer.log:2023-11-21 23:36:55.776 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "bridge","bond","iface","id" FROM vm_iface2bond2bridge WHERE bridge = 2' duration=175
  93. vm_1_writer.log:2023-11-21 23:36:55.776 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id, name, state FROM vm_node_interfaces WHERE node='2'' duration=214
  94. vm_1_writer.log:2023-11-21 23:36:55.776 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id, name, state FROM vm_node_bond WHERE node='2'' duration=156
  95. vm_1_writer.log:2023-11-21 23:36:55.776 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT id, name, state FROM vm_node_bridge WHERE node='2'' duration=142
  96. vm_1_writer.log:2023-11-21 23:36:55.777 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT s.name, s.script, s.type, s.priority FROM vm_node_script s LEFT JOIN vm_node_script2cluster n_s2c ON n_s2c.script=s.id WHERE n_s2c.cluster='1'' duration=761
  97. vm_1_writer.log:2023-11-21 23:36:55.779 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "value","name","id" FROM vm_settings WHERE "name"='task_timeout'' duration=171
  98. vm_1_writer.log:2023-11-21 23:36:55.779 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "value","name","id" FROM vm_settings WHERE "name"='consul_task_ttl_in_sec'' duration=111
  99. vm_1_writer.log:2023-11-21 23:36:55.796 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "security_action","ha_cluster_id","ha_id","password_hidden","defer_reason","request_info","node","main_table_name","main_table_id","main_table","output","date_end","date_start","date_create","status","message_params","param","name","consul_id","id" FROM vm_task_log WHERE "consul_id"='79' AND "name"='node_create'' duration=394
  100. vm_1_writer.log:2023-11-21 23:36:55.796 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_task_log ("id","consul_id","name","param","message_params","status","main_table","main_table_id","main_table_name","node","request_info") VALUES(12,79,'node_create', E'["--action","node_create","--virt-type","kvm","--log-name","node_create/node_2","--params","{\\"autorun_scripts\\":[],\\"changed\\":[],\\"cluster_id\\":1,\\"datacenter_type\\":\\"common\\",\\"deleted\\":[],\\"gateway\\":null,\\"id\\":2,\\"iface_list\\":[{\\"id\\":2,\\"name\\":\\"eth0\\",\\"nm_ruled\\":null,\\"state\\":\\"changed\\",\\"type\\":\\"eth\\"},{\\"id\\":2,\\"name\\":\\"vmbr0\\",\\"nm_ruled\\":null,\\"state\\":\\"new\\",\\"type\\":\\"bridge\\"}],\\"image_storage_path\\":\\"/image\\",\\"ip\\":\\"172.31.36.17\\",\\"network_autosetup_disabled\\":false,\\"new\\":[{\\"gateway_v4\\":\\"172.31.36.1\\",\\"gateway_v6\\":null,\\"id\\":2,\\"ipv4\\":[\\"172.31.36.17/23\\"],\\"ipv6\\":[],\\"name\\":\\"vmbr0\\",\\"old_slaves\\":[],\\"old_take_slave_ip\\":null,\\"old_vlan\\":null,\\"slaves\\":[{\\"id\\":2,\\"name\\":\\"eth0\\",\\"type\\":\\"eth\\"}],\\"take_slave_ip\\":true,\\"type\\":\\"bridge\\",\\"vlan\\":null}],\\"nm_ruled\\":false,\\"node\\":{\\"connection\\":\\"eyJzc2hfYWRkcmVzcyI6IjE3Mi4zMS4zNi4xNyIsInNzaF9wb3J0IjoyMiwic3NoX3VzZXIiOiJhc3RyYS1ub2RlMiJ9\\"},\\"node_addr_v6\\":null,\\"node_interface_name\\":\\"eth0\\",\\"os_major_version\\":\\"1.7\\",\\"os_name\\":\\"astra\\",\\"os_storage_path\\":\\"/share\\",\\"os_version\\":\\"Astra Linux 1.7_x86-64\\",\\"proxy_enabled\\":false,\\"spice_enabled\\":true,\\"ssh_port\\":22,\\"ssh_user\\":\\"astra-node2\\",\\"timeout\\":300,\\"timezone\\":\\"UTC\\"}"]','{"ip_addr":"172.31.36.17","name":"node2"}','created','vm_node',2,'node2',2,'{"callback_counter":31,"first_start":1504273360642,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":100000,"name":"n.mamaev@ispsystem.com"}},"runtime":1439027357}')' duration=570
  101. vm_1_writer.log:2023-11-21 23:36:55.800 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT vm_storage2cluster.storage AS storage FROM vm_storage2cluster WHERE (vm_storage2cluster.cluster='1')' duration=1591
  102. vm_1_writer.log:2023-11-21 23:36:55.800 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "imported_from","vm5_data","is_network","storage_params","state","type","comment","name","id" FROM vm_storage WHERE "id"='1'' duration=469
  103. vm_1_writer.log:2023-11-21 23:36:55.801 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "hdd_overselling","ha_params","params","pool_name","enabled","is_main","cluster","storage","id" FROM vm_storage2cluster WHERE "storage"='1' AND "cluster"='1'' duration=247
  104. vm_1_writer.log:2023-11-21 23:36:55.802 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_storage2node ("id","storage","node","state","hdd_overselling") VALUES(2,1,2,'creating',1.000000)' duration=1222
  105. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] request method: POST url: /task/79/internal_edit version: HTTP/1.0
  106. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Handler 'task/{task_id}/internal_edit' choosen
  107. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [connection]close
  108. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "value","name","id" FROM vm_settings WHERE "name"='task_timeout'' duration=188
  109. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [content-length]41
  110. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [global-attributes]{"callback_counter":5,"first_start":1505716978299,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":0,"name":""}},"runtime":485891}
  111. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [host]instance-1
  112. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [instance-id]1
  113. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  114. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-forwarded-for]172.18.0.26
  115. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-remote-ip]172.18.0.26
  116. vm_1_writer.log:2023-11-21 23:36:55.803 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-request-id]fad961cdc8b8b4b201138a23cf45b04c
  117. vm_1_writer.log:2023-11-21 23:36:55.804 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"name":"node_create","status":"running"}
  118. vm_1_writer.log:2023-11-21 23:36:55.804 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  119. vm_1_writer.log:2023-11-21 23:36:55.804 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Invoke POST request callback
  120. vm_1_writer.log:2023-11-21 23:36:55.804 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "value","name","id" FROM vm_settings WHERE "name"='consul_task_ttl_in_sec'' duration=632
  121. vm_1_writer.log:2023-11-21 23:36:55.804 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] WriterAsyncProcess
  122. vm_1_writer.log:2023-11-21 23:36:55.822 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Notification is created completely
  123. vm_1_writer.log:2023-11-21 23:36:55.836 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "security_action","ha_cluster_id","ha_id","password_hidden","defer_reason","request_info","node","main_table_name","main_table_id","main_table","output","date_end","date_start","date_create","status","message_params","param","name","consul_id","id" FROM vm_task_log WHERE "consul_id"='80' AND "name"='connect_storages'' duration=335
  124. vm_1_writer.log:2023-11-21 23:36:55.837 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_task_log ("id","consul_id","name","param","message_params","status","main_table","main_table_id","main_table_name","request_info") VALUES(13,80,'connect_storages', E'["--action","connect_storages","--virt-type","kvm","--params","{\\"cluster_id\\":1,\\"node_id\\":2,\\"node_ip\\":\\"172.31.36.17\\",\\"node_ssh_port\\":22,\\"storages\\":[{\\"id\\":1,\\"type\\":\\"file\\"}]}"]','{"name":"node2"}','created','vm_node',2,'node2','{"callback_counter":40,"first_start":1504273360642,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":100000,"name":"n.mamaev@ispsystem.com"}},"runtime":1455185658}')' duration=345
  125. vm_1_writer.log:2023-11-21 23:36:55.838 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "value","name","id" FROM vm_settings WHERE "name"='task_timeout'' duration=194
  126. vm_1_writer.log:2023-11-21 23:36:55.838 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "value","name","id" FROM vm_settings WHERE "name"='consul_task_ttl_in_sec'' duration=156
  127. vm_1_writer.log:2023-11-21 23:36:55.853 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='SELECT "security_action","ha_cluster_id","ha_id","password_hidden","defer_reason","request_info","node","main_table_name","main_table_id","main_table","output","date_end","date_start","date_create","status","message_params","param","name","consul_id","id" FROM vm_task_log WHERE "consul_id"='81' AND "name"='node_create_finish'' duration=378
  128. vm_1_writer.log:2023-11-21 23:36:55.854 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_task_log ("id","consul_id","name","param","message_params","status","main_table","main_table_id","request_info") VALUES(14,81,'node_create_finish', E'["--action","node_create_finish","--virt-type","kvm","--params","{\\"id\\":2}"]','{"name":"node2"}','created','vm_node',2,'{"callback_counter":46,"first_start":1504273360642,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":100000,"name":"n.mamaev@ispsystem.com"}},"runtime":1472396063}')' duration=375
  129. vm_1_writer.log:2023-11-21 23:36:55.859 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943403b210 query='INSERT INTO vm_node_log ("id","name","node","task","request_trustee","request_owner") VALUES(4,'node_create',2,12,100000,100000)' duration=2116
  130. vm_1_writer.log:2023-11-21 23:36:55.859 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Response body '{"finish_task":81,"id":2,"storages_task":80,"task":79}'
  131. vm_1_writer.log:2023-11-21 23:36:55.859 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Writer process duration: 1503
  132. vm_1_writer.log:2023-11-21 23:36:55.860 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] LimitAssert
  133. vm_1_writer.log:2023-11-21 23:36:55.862 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x76943c03fa80 query='SELECT "security_action","ha_cluster_id","ha_id","password_hidden","defer_reason","request_info","node","main_table_name","main_table_id","main_table","output","date_end","date_start","date_create","status","message_params","param","name","consul_id","id" FROM vm_task_log WHERE "consul_id"='79' AND "name"='node_create'' duration=1992
  134. vm_1_writer.log:2023-11-21 23:36:55.864 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x76943c03fa80 query='UPDATE vm_task_log SET "status"='running',"date_start"='2023-11-21 23:36:55' WHERE "id"=12' duration=1066
  135. vm_1_writer.log:2023-11-21 23:36:55.864 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x76943c03fa80 query='SELECT id FROM vm_host_log WHERE task='79'' duration=370
  136. vm_1_writer.log:2023-11-21 23:36:55.864 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x76943c03fa80 query='SELECT id FROM vm_node_log WHERE task='79'' duration=146
  137. vm_1_writer.log:2023-11-21 23:36:55.865 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Response body '{"id":79}'
  138. vm_1_writer.log:2023-11-21 23:36:55.865 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Writer process duration: 5
  139. vm_1_writer.log:2023-11-21 23:36:55.872 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Notification is created completely
  140. vm_1_writer.log:2023-11-21 23:36:55.872 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Notification is created completely
  141. vm_1_writer.log:2023-11-21 23:36:55.872 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Notification is created completely
  142. vm_1_writer.log:2023-11-21 23:36:55.874 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Notification is created completely
  143. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] request method: POST url: /node/2 version: HTTP/1.0
  144. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Handler 'node/{node_id}' choosen
  145. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [connection]close
  146. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [content-length]43
  147. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [global-attributes]{"callback_counter":18,"first_start":1506299708359,"request":{"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"name":"n.mamaev@ispsystem.com"}},"runtime":59635473192}
  148. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [host]instance-1
  149. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [instance-id]1
  150. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  151. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-forwarded-for]172.18.0.26
  152. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-remote-ip]172.18.0.26
  153. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-request-id]443e420ede8b25dfd6f47539379e64ea
  154. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] RequestBody: {"values":{"state":"setup_virtualization"}}
  155. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] End of POST request
  156. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Invoke POST request callback
  157. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] WriterAsyncProcess
  158. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] LimitAssert
  159. vm_1_writer.log:2023-11-21 23:37:55.506 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [vm_security][1700609875506][internal] Edit node node id 2 starts with params: {"values":{"state":"setup_virtualization"}}
  160. vm_1_writer.log:2023-11-21 23:37:55.508 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c046a10 query='SELECT "nm_ruled","additional_data","vm5_data","update_dc_networks_failed","network_error","network_settings_lock","ha_error","ha_disable_failed","ha_state","host_filter","host_limit","selinux_enforcing","hostname","overselling","lxd_version","qemu_version","libvirt_version","uptime","kernel_version","os_version","metrics_timestamp","mon_install_date","mon_installed","host_creation_blocked","property","disk_params","gray_ips","problems","spice_error","bird_error","lxd_error","libvirt_error","frr_error","connection_error","maintenance_mode","state","ssh_user","ssh_port","vnc_addr","ip_addr_v6","ip_addr","socket_number","vcpu_limit","cpu_number","max_vcpu_number","ram_mib","cluster","comment","name","id" FROM vm_node WHERE "id"='2'' duration=562
  161. vm_1_writer.log:2023-11-21 23:37:55.508 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c046a10 query='SELECT "balancer_config","balancer_mode","vm5_data","spice_enabled","node_os_family","vxlan_mode","node_network_gateway","node_network_timeout","ha_error","ha_cluster_id","ha_agent_version","ha_checking_host","ha_enabled","net_bandwidth_mbitps","dns_servers","host_per_node_limit","proxy_enabled","domain_change_allowed","manage_disk_enabled","iso_enabled","cpu_overselling","overselling","qemu_version","domain_template","image_storage_path","os_storage_path","interface_count","imported_from","host_filter","host_distribution_policy","datacenter_type","virtualization_type","time_zone","comment","name","id" FROM vm_cluster WHERE "id"='1'' duration=350
  162. vm_1_writer.log:2023-11-21 23:37:55.613 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c046a10 query='UPDATE vm_node SET "state"='setup_virtualization' WHERE "id"=2' duration=104250
  163. vm_1_writer.log:2023-11-21 23:37:55.613 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c046a10 query='SELECT MAX(create_time) FROM vm_node_history WHERE event_type='field:state' AND ref='2'' duration=417
  164. vm_1_writer.log:2023-11-21 23:37:55.614 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c046a10 query='INSERT INTO vm_node_history (id,prev_time,event_type,event_info,request_user,request_owner,request_ip,request_id,ref) VALUES (5,'2023-11-21 23:36:55.583026','field:state','{"new_value":"setup_virtualization","old_value":"setup_virtualization"}','n.mamaev@ispsystem.com','---','127.0.0.1','ecca388e597bb9313f07e86242a51874',2)' duration=423
  165. vm_1_writer.log:2023-11-21 23:37:55.616 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [vm_security][1700609875506][internal] Edit node node id 2 successfully completed
  166. vm_1_writer.log:2023-11-21 23:37:55.616 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Response body '{"id":2}'
  167. vm_1_writer.log:2023-11-21 23:37:55.616 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Writer process duration: 109
  168. vm_1_writer.log:2023-11-21 23:37:55.619 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Notification is created completely
  169. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] request method: POST url: /node/2 version: HTTP/1.0
  170. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Handler 'node/{node_id}' choosen
  171. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [connection]close
  172. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [content-length]30
  173. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [global-attributes]{"callback_counter":30,"first_start":1506299708359,"request":{"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"name":"n.mamaev@ispsystem.com"}},"runtime":86382589395}
  174. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [host]instance-1
  175. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [instance-id]1
  176. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  177. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-forwarded-for]172.18.0.26
  178. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-remote-ip]172.18.0.26
  179. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-request-id]551d5ee44d3b7b5aa13066d18611c37b
  180. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] RequestBody: {"values":{"state":"crashed"}}
  181. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] End of POST request
  182. vm_1_writer.log:2023-11-21 23:38:22.253 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Invoke POST request callback
  183. vm_1_writer.log:2023-11-21 23:38:22.254 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] WriterAsyncProcess
  184. vm_1_writer.log:2023-11-21 23:38:22.254 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] LimitAssert
  185. vm_1_writer.log:2023-11-21 23:38:22.254 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [vm_security][1700609902254][internal] Edit node node id 2 starts with params: {"values":{"state":"crashed"}}
  186. vm_1_writer.log:2023-11-21 23:38:22.254 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c002fb0 query='SELECT "nm_ruled","additional_data","vm5_data","update_dc_networks_failed","network_error","network_settings_lock","ha_error","ha_disable_failed","ha_state","host_filter","host_limit","selinux_enforcing","hostname","overselling","lxd_version","qemu_version","libvirt_version","uptime","kernel_version","os_version","metrics_timestamp","mon_install_date","mon_installed","host_creation_blocked","property","disk_params","gray_ips","problems","spice_error","bird_error","lxd_error","libvirt_error","frr_error","connection_error","maintenance_mode","state","ssh_user","ssh_port","vnc_addr","ip_addr_v6","ip_addr","socket_number","vcpu_limit","cpu_number","max_vcpu_number","ram_mib","cluster","comment","name","id" FROM vm_node WHERE "id"='2'' duration=451
  187. vm_1_writer.log:2023-11-21 23:38:22.255 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c002fb0 query='SELECT "balancer_config","balancer_mode","vm5_data","spice_enabled","node_os_family","vxlan_mode","node_network_gateway","node_network_timeout","ha_error","ha_cluster_id","ha_agent_version","ha_checking_host","ha_enabled","net_bandwidth_mbitps","dns_servers","host_per_node_limit","proxy_enabled","domain_change_allowed","manage_disk_enabled","iso_enabled","cpu_overselling","overselling","qemu_version","domain_template","image_storage_path","os_storage_path","interface_count","imported_from","host_filter","host_distribution_policy","datacenter_type","virtualization_type","time_zone","comment","name","id" FROM vm_cluster WHERE "id"='1'' duration=250
  188. vm_1_writer.log:2023-11-21 23:38:22.345 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c002fb0 query='UPDATE vm_node SET "state"='crashed' WHERE "id"=2' duration=90035
  189. vm_1_writer.log:2023-11-21 23:38:22.346 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c002fb0 query='SELECT MAX(create_time) FROM vm_node_history WHERE event_type='field:state' AND ref='2'' duration=411
  190. vm_1_writer.log:2023-11-21 23:38:22.346 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x76943c002fb0 query='INSERT INTO vm_node_history (id,prev_time,event_type,event_info,request_user,request_owner,request_ip,request_id,ref) VALUES (6,'2023-11-21 23:37:55.508934','field:state','{"new_value":"crashed","old_value":"crashed"}','n.mamaev@ispsystem.com','---','127.0.0.1','ecca388e597bb9313f07e86242a51874',2)' duration=888
  191. vm_1_writer.log:2023-11-21 23:38:22.349 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [vm_security][1700609902254][internal] Edit node node id 2 successfully completed
  192. vm_1_writer.log:2023-11-21 23:38:22.349 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Response body '{"id":2}'
  193. vm_1_writer.log:2023-11-21 23:38:22.349 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Writer process duration: 95
  194. vm_1_writer.log:2023-11-21 23:38:22.353 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Notification is created completely
  195. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] request method: POST url: /task/79/fail?name=node%5Fcreate&params=%7B%7D version: HTTP/1.1
  196. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Handler 'task/{task_id}/fail' choosen
  197. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [connection]close
  198. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [content-length]829
  199. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [host]localhost
  200. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [instance-id]1
  201. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  202. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-forwarded-for]127.0.0.1
  203. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-remote-ip]127.0.0.1
  204. vm_1_writer.log:2023-11-21 23:38:22.367 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-request-id]ecca388e597bb9313f07e86242a51874
  205. vm_1_writer.log:2023-11-21 23:38:22.368 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"output":{"content":"Unhandled exception: failed to parse script output: '{\"started\": true, \"error\": \"failed to configure network, changes have been reverted\", \"reverted\": true}{\"started\": true, \"error\": \"failed to configure network, changes have been reverted\", \"reverted\": true}'","type":"text"},"params":{"changed":[],"deleted":[],"iface_list":[{"id":2,"name":"eth0","nm_ruled":null,"state":"changed","type":"eth"},{"id":2,"name":"vmbr0","nm_ruled":null,"state":"new","type":"bridge"}],"import":false,"new":[{"gateway_v4":"172.31.36.1","gateway_v6":null,"id":2,"ipv4":["172.31.36.17/23"],"ipv6":[],"name":"vmbr0","old_slaves":[],"old_take_slave_ip":null,"old_vlan":null,"slaves":[{"id":2,"name":"eth0","type":"eth"}],"take_slave_ip":true,"type":"bridge","vlan":null}],"node_id":2,"virtualization_type":"kvm"}}
  206. vm_1_writer.log:2023-11-21 23:38:22.368 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  207. vm_1_writer.log:2023-11-21 23:38:22.368 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Invoke POST request callback
  208. vm_1_writer.log:2023-11-21 23:38:22.368 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Executing event for hanlder task/{task_id}/fail
  209. vm_1_writer.log:2023-11-21 23:38:22.368 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] InternalAsyncCall service: vm path: task/79/internal_edit
  210. vm_1_writer.log:2023-11-21 23:38:22.371 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] NetworkConfigureFail params: {"changed":[],"deleted":[],"iface_list":[{"id":2,"name":"eth0","nm_ruled":null,"state":"changed","type":"eth"},{"id":2,"name":"vmbr0","nm_ruled":null,"state":"new","type":"bridge"}],"import":false,"new":[{"gateway_v4":"172.31.36.1","gateway_v6":null,"id":2,"ipv4":["172.31.36.17/23"],"ipv6":[],"name":"vmbr0","old_slaves":[],"old_take_slave_ip":null,"old_vlan":null,"slaves":[{"id":2,"name":"eth0","type":"eth"}],"take_slave_ip":true,"type":"bridge","vlan":null}],"node_id":2,"virtualization_type":"kvm"}
  211. vm_1_writer.log:2023-11-21 23:38:22.371 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] NetworkConfigureFail output: {"full_output":"Unhandled exception: failed to parse script output: '{\"started\": true, \"error\": \"failed to configure network, changes have been reverted\", \"reverted\": true}{\"started\": true, \"error\": \"failed to configure network, changes have been reverted\", \"reverted\": true}'"}
  212. vm_1_writer.log:2023-11-21 23:38:22.372 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] request method: POST url: /task/79/internal_edit version: HTTP/1.0
  213. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Handler 'task/{task_id}/internal_edit' choosen
  214. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [connection]close
  215. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [content-length]354
  216. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [global-attributes]{"callback_counter":5,"first_start":1592284329698,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":0,"name":""}},"runtime":1121503}
  217. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [host]instance-1
  218. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [instance-id]1
  219. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  220. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-forwarded-for]172.18.0.26
  221. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-remote-ip]172.18.0.26
  222. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-request-id]6212048684e2df9f7cb1ff2c30b6ac8f
  223. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x76943c047a70 query='SELECT "nm_ruled","additional_data","vm5_data","update_dc_networks_failed","network_error","network_settings_lock","ha_error","ha_disable_failed","ha_state","host_filter","host_limit","selinux_enforcing","hostname","overselling","lxd_version","qemu_version","libvirt_version","uptime","kernel_version","os_version","metrics_timestamp","mon_install_date","mon_installed","host_creation_blocked","property","disk_params","gray_ips","problems","spice_error","bird_error","lxd_error","libvirt_error","frr_error","connection_error","maintenance_mode","state","ssh_user","ssh_port","vnc_addr","ip_addr_v6","ip_addr","socket_number","vcpu_limit","cpu_number","max_vcpu_number","ram_mib","cluster","comment","name","id" FROM vm_node WHERE "id"='2'' duration=1749
  224. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"name":"node_create","output":{"content":"Unhandled exception: failed to parse script output: '{\"started\": true, \"error\": \"failed to configure network, changes have been reverted\", \"reverted\": true}{\"started\": true, \"error\": \"failed to configure network, changes have been reverted\", \"reverted\": true}'","type":"text"},"status":"failed"}
  225. vm_1_writer.log:2023-11-21 23:38:22.373 [pid=7504] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  226. vm_1_writer.log:2023-11-21 23:38:32.260 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] request method: POST url: /task/80/internal_edit version: HTTP/1.0
  227. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Handler 'task/{task_id}/internal_edit' choosen
  228. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [connection]close
  229. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [content-length]46
  230. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [global-attributes]{"callback_counter":5,"first_start":1592625522976,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":0,"name":""}},"runtime":455887}
  231. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [host]instance-1
  232. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [instance-id]1
  233. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  234. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-forwarded-for]172.18.0.26
  235. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-remote-ip]172.18.0.26
  236. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-request-id]109f4968909682b0622019968e41d175
  237. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Skipped permission check due to env setting
  238. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"name":"connect_storages","status":"running"}
  239. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  240. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Invoke POST request callback
  241. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] WriterAsyncProcess
  242. vm_1_writer.log:2023-11-21 23:38:32.261 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] LimitAssert
  243. vm_1_writer.log:2023-11-21 23:38:32.266 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2400e880 query='SELECT "security_action","ha_cluster_id","ha_id","password_hidden","defer_reason","request_info","node","main_table_name","main_table_id","main_table","output","date_end","date_start","date_create","status","message_params","param","name","consul_id","id" FROM vm_task_log WHERE "consul_id"='80' AND "name"='connect_storages'' duration=1407
  244. vm_1_writer.log:2023-11-21 23:38:32.267 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2400e880 query='UPDATE vm_task_log SET "status"='running',"date_start"='2023-11-21 23:38:32' WHERE "id"=13' duration=901
  245. vm_1_writer.log:2023-11-21 23:38:32.267 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2400e880 query='SELECT id FROM vm_host_log WHERE task='80'' duration=324
  246. vm_1_writer.log:2023-11-21 23:38:32.267 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2400e880 query='SELECT id FROM vm_node_log WHERE task='80'' duration=313
  247. vm_1_writer.log:2023-11-21 23:38:32.268 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Response body '{"id":80}'
  248. vm_1_writer.log:2023-11-21 23:38:32.268 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Writer process duration: 6
  249. vm_1_writer.log:2023-11-21 23:38:32.270 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Notification is created completely
  250. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] request method: POST url: /task/80/fail?name=connect%5Fstorages&params=%7B%7D version: HTTP/1.1
  251. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Handler 'task/{task_id}/fail' choosen
  252. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [connection]close
  253. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [content-length]473
  254. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [host]localhost
  255. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [instance-id]1
  256. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  257. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-forwarded-for]127.0.0.1
  258. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-remote-ip]127.0.0.1
  259. vm_1_writer.log:2023-11-21 23:38:34.543 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-request-id]ecca388e597bb9313f07e86242a51874
  260. vm_1_writer.log:2023-11-21 23:38:34.544 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"output":{"content":"Unhandled exception: Traceback (most recent call last):\n  File \"scripts/kvm/connect_storages.py\", line 167, in <module>\n    main()\n  File \"scripts/kvm/connect_storages.py\", line 120, in main\n    raise RuntimeError(f\"Node {params['node_id']} is neither active nor in preparing resources state\")\nRuntimeError: Node 2 is neither active nor in preparing resources state","type":"text"},"params":{"cluster_id":1,"main_storage_id":1,"node_id":2}}
  261. vm_1_writer.log:2023-11-21 23:38:34.544 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  262. vm_1_writer.log:2023-11-21 23:38:34.544 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Invoke POST request callback
  263. vm_1_writer.log:2023-11-21 23:38:34.544 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Executing event for hanlder task/{task_id}/fail
  264. vm_1_writer.log:2023-11-21 23:38:34.544 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] InternalAsyncCall service: vm path: task/80/internal_edit
  265. vm_1_writer.log:2023-11-21 23:38:34.546 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x3690eb0 query='SELECT "nm_ruled","additional_data","vm5_data","update_dc_networks_failed","network_error","network_settings_lock","ha_error","ha_disable_failed","ha_state","host_filter","host_limit","selinux_enforcing","hostname","overselling","lxd_version","qemu_version","libvirt_version","uptime","kernel_version","os_version","metrics_timestamp","mon_install_date","mon_installed","host_creation_blocked","property","disk_params","gray_ips","problems","spice_error","bird_error","lxd_error","libvirt_error","frr_error","connection_error","maintenance_mode","state","ssh_user","ssh_port","vnc_addr","ip_addr_v6","ip_addr","socket_number","vcpu_limit","cpu_number","max_vcpu_number","ram_mib","cluster","comment","name","id" FROM vm_node WHERE "id"='2'' duration=1305
  266. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] request method: POST url: /task/80/internal_edit version: HTTP/1.0
  267. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Handler 'task/{task_id}/internal_edit' choosen
  268. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [connection]close
  269. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [content-length]459
  270. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [global-attributes]{"callback_counter":5,"first_start":1604460854791,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":0,"name":""}},"runtime":677341}
  271. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [host]instance-1
  272. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [instance-id]1
  273. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  274. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-forwarded-for]172.18.0.26
  275. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-remote-ip]172.18.0.26
  276. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-request-id]3326811aa9a7cce2012355b2a0f1a25d
  277. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x3690eb0 query='SELECT "balancer_config","balancer_mode","vm5_data","spice_enabled","node_os_family","vxlan_mode","node_network_gateway","node_network_timeout","ha_error","ha_cluster_id","ha_agent_version","ha_checking_host","ha_enabled","net_bandwidth_mbitps","dns_servers","host_per_node_limit","proxy_enabled","domain_change_allowed","manage_disk_enabled","iso_enabled","cpu_overselling","overselling","qemu_version","domain_template","image_storage_path","os_storage_path","interface_count","imported_from","host_filter","host_distribution_policy","datacenter_type","virtualization_type","time_zone","comment","name","id" FROM vm_cluster WHERE "id"='1'' duration=768
  278. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"name":"connect_storages","output":{"content":"Unhandled exception: Traceback (most recent call last):\n  File \"scripts/kvm/connect_storages.py\", line 167, in <module>\n    main()\n  File \"scripts/kvm/connect_storages.py\", line 120, in main\n    raise RuntimeError(f\"Node {params['node_id']} is neither active nor in preparing resources state\")\nRuntimeError: Node 2 is neither active nor in preparing resources state","type":"text"},"status":"failed"}
  279. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  280. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Invoke POST request callback
  281. vm_1_writer.log:2023-11-21 23:38:34.547 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] WriterAsyncProcess
  282. vm_1_writer.log:2023-11-21 23:38:34.548 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] LimitAssert
  283. vm_1_writer.log:2023-11-21 23:38:34.549 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f240054a0 query='SELECT "security_action","ha_cluster_id","ha_id","password_hidden","defer_reason","request_info","node","main_table_name","main_table_id","main_table","output","date_end","date_start","date_create","status","message_params","param","name","consul_id","id" FROM vm_task_log WHERE "consul_id"='80' AND "name"='connect_storages'' duration=423
  284. vm_1_writer.log:2023-11-21 23:38:34.551 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f240054a0 query='UPDATE vm_task_log SET "status"='failed',"date_end"='2023-11-21 23:38:34',"output"='Unhandled exception: Traceback (most recent call last):
  285. vm_1_writer.log:2023-11-21 23:38:34.551 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f240054a0 query='SELECT id FROM vm_host_log WHERE task='80'' duration=208
  286. vm_1_writer.log:2023-11-21 23:38:34.551 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f240054a0 query='SELECT id FROM vm_node_log WHERE task='80'' duration=160
  287. vm_1_writer.log:2023-11-21 23:38:34.552 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Response body '{"id":80}'
  288. vm_1_writer.log:2023-11-21 23:38:34.552 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Writer process duration: 3
  289. vm_1_writer.log:2023-11-21 23:38:34.555 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Notification is created completely
  290. vm_1_writer.log:2023-11-21 23:38:34.566 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] request method: POST url: /task/81/internal_edit version: HTTP/1.0
  291. vm_1_writer.log:2023-11-21 23:38:34.566 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Handler 'task/{task_id}/internal_edit' choosen
  292. vm_1_writer.log:2023-11-21 23:38:34.566 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [connection]close
  293. vm_1_writer.log:2023-11-21 23:38:34.566 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [content-length]48
  294. vm_1_writer.log:2023-11-21 23:38:34.566 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [global-attributes]{"callback_counter":5,"first_start":1604475493874,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":0,"name":""}},"runtime":152385}
  295. vm_1_writer.log:2023-11-21 23:38:34.566 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [host]instance-1
  296. vm_1_writer.log:2023-11-21 23:38:34.566 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [instance-id]1
  297. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  298. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-forwarded-for]172.18.0.26
  299. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-remote-ip]172.18.0.26
  300. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-request-id]3380c190d65c41edd5046bbd99f6b8df
  301. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"name":"node_create_finish","status":"running"}
  302. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  303. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Invoke POST request callback
  304. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] WriterAsyncProcess
  305. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] LimitAssert
  306. vm_1_writer.log:2023-11-21 23:38:34.567 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c024360 query='SELECT "security_action","ha_cluster_id","ha_id","password_hidden","defer_reason","request_info","node","main_table_name","main_table_id","main_table","output","date_end","date_start","date_create","status","message_params","param","name","consul_id","id" FROM vm_task_log WHERE "consul_id"='81' AND "name"='node_create_finish'' duration=478
  307. vm_1_writer.log:2023-11-21 23:38:34.569 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c024360 query='UPDATE vm_task_log SET "status"='running',"date_start"='2023-11-21 23:38:34' WHERE "id"=14' duration=837
  308. vm_1_writer.log:2023-11-21 23:38:34.569 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c024360 query='SELECT id FROM vm_host_log WHERE task='81'' duration=620
  309. vm_1_writer.log:2023-11-21 23:38:34.570 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c024360 query='SELECT id FROM vm_node_log WHERE task='81'' duration=293
  310. vm_1_writer.log:2023-11-21 23:38:34.570 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Response body '{"id":81}'
  311. vm_1_writer.log:2023-11-21 23:38:34.570 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Writer process duration: 3
  312. vm_1_writer.log:2023-11-21 23:38:34.581 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Notification is created completely
  313. vm_1_writer.log:2023-11-21 23:38:34.621 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] request method: POST url: /node/2 version: HTTP/1.0
  314. vm_1_writer.log:2023-11-21 23:38:34.621 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Handler 'node/{node_id}' choosen
  315. vm_1_writer.log:2023-11-21 23:38:34.621 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [connection]close
  316. vm_1_writer.log:2023-11-21 23:38:34.621 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [content-length]30
  317. vm_1_writer.log:2023-11-21 23:38:34.621 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [global-attributes]{"callback_counter":6,"first_start":1604534697979,"request":{"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"name":"n.mamaev@ispsystem.com"}},"runtime":8352263}
  318. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [host]instance-1
  319. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [instance-id]1
  320. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  321. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-forwarded-for]172.18.0.26
  322. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-remote-ip]172.18.0.26
  323. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got header: [x-request-id]8d9c1d2afcaf5c1ffd4dd45cedf7fa58
  324. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] RequestBody: {"values":{"state":"crashed"}}
  325. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] End of POST request
  326. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Invoke POST request callback
  327. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] WriterAsyncProcess
  328. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] LimitAssert
  329. vm_1_writer.log:2023-11-21 23:38:34.622 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [vm_security][1700609914622][internal] Edit node node id 2 starts with params: {"values":{"state":"crashed"}}
  330. vm_1_writer.log:2023-11-21 23:38:34.623 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x7d2f2400f080 query='SELECT "nm_ruled","additional_data","vm5_data","update_dc_networks_failed","network_error","network_settings_lock","ha_error","ha_disable_failed","ha_state","host_filter","host_limit","selinux_enforcing","hostname","overselling","lxd_version","qemu_version","libvirt_version","uptime","kernel_version","os_version","metrics_timestamp","mon_install_date","mon_installed","host_creation_blocked","property","disk_params","gray_ips","problems","spice_error","bird_error","lxd_error","libvirt_error","frr_error","connection_error","maintenance_mode","state","ssh_user","ssh_port","vnc_addr","ip_addr_v6","ip_addr","socket_number","vcpu_limit","cpu_number","max_vcpu_number","ram_mib","cluster","comment","name","id" FROM vm_node WHERE "id"='2'' duration=612
  331. vm_1_writer.log:2023-11-21 23:38:34.624 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] db: id=0x7d2f2400f080 query='SELECT "balancer_config","balancer_mode","vm5_data","spice_enabled","node_os_family","vxlan_mode","node_network_gateway","node_network_timeout","ha_error","ha_cluster_id","ha_agent_version","ha_checking_host","ha_enabled","net_bandwidth_mbitps","dns_servers","host_per_node_limit","proxy_enabled","domain_change_allowed","manage_disk_enabled","iso_enabled","cpu_overselling","overselling","qemu_version","domain_template","image_storage_path","os_storage_path","interface_count","imported_from","host_filter","host_distribution_policy","datacenter_type","virtualization_type","time_zone","comment","name","id" FROM vm_cluster WHERE "id"='1'' duration=320
  332. vm_1_writer.log:2023-11-21 23:38:34.624 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] [vm_security][1700609914622][internal] Edit node node id 2 successfully completed
  333. vm_1_writer.log:2023-11-21 23:38:34.624 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Response body '{"id":2}'
  334. vm_1_writer.log:2023-11-21 23:38:34.624 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Writer process duration: 2
  335. vm_1_writer.log:2023-11-21 23:38:34.629 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Notification is created completely
  336. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] request method: POST url: /task/81/fail?name=node%5Fcreate%5Ffinish&params=%7B%7D version: HTTP/1.1
  337. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Handler 'task/{task_id}/fail' choosen
  338. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [connection]close
  339. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [content-length]155
  340. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [host]localhost
  341. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [instance-id]1
  342. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  343. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-forwarded-for]127.0.0.1
  344. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-remote-ip]127.0.0.1
  345. vm_1_writer.log:2023-11-21 23:38:34.639 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1] Got header: [x-request-id]ecca388e597bb9313f07e86242a51874
  346. vm_1_writer.log:2023-11-21 23:38:34.641 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"output":{"content":"Unhandled exception: node #2 is not in storage ready state","type":"text"},"params":{"cluster_id":1,"main_storage_id":1,"node_id":2}}
  347. vm_1_writer.log:2023-11-21 23:38:34.641 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  348. vm_1_writer.log:2023-11-21 23:38:34.641 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Invoke POST request callback
  349. vm_1_writer.log:2023-11-21 23:38:34.641 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Executing event for hanlder task/{task_id}/fail
  350. vm_1_writer.log:2023-11-21 23:38:34.641 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] InternalAsyncCall service: vm path: task/81/internal_edit
  351. vm_1_writer.log:2023-11-21 23:38:34.642 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c002580 query='SELECT "nm_ruled","additional_data","vm5_data","update_dc_networks_failed","network_error","network_settings_lock","ha_error","ha_disable_failed","ha_state","host_filter","host_limit","selinux_enforcing","hostname","overselling","lxd_version","qemu_version","libvirt_version","uptime","kernel_version","os_version","metrics_timestamp","mon_install_date","mon_installed","host_creation_blocked","property","disk_params","gray_ips","problems","spice_error","bird_error","lxd_error","libvirt_error","frr_error","connection_error","maintenance_mode","state","ssh_user","ssh_port","vnc_addr","ip_addr_v6","ip_addr","socket_number","vcpu_limit","cpu_number","max_vcpu_number","ram_mib","cluster","comment","name","id" FROM vm_node WHERE "id"='2'' duration=524
  352. vm_1_writer.log:2023-11-21 23:38:34.643 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Task '81', all after execute events completed
  353. vm_1_writer.log:2023-11-21 23:38:34.643 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Response body 'null'
  354. vm_1_writer.log:2023-11-21 23:38:34.647 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Notification is created completely
  355. vm_1_writer.log:2023-11-21 23:38:34.649 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] request method: POST url: /task/81/internal_edit version: HTTP/1.0
  356. vm_1_writer.log:2023-11-21 23:38:34.649 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Handler 'task/{task_id}/internal_edit' choosen
  357. vm_1_writer.log:2023-11-21 23:38:34.649 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [connection]close
  358. vm_1_writer.log:2023-11-21 23:38:34.649 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [content-length]143
  359. vm_1_writer.log:2023-11-21 23:38:34.649 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [global-attributes]{"callback_counter":5,"first_start":1604556732921,"need_log":true,"request":{"extra_tags":[],"id":"ecca388e597bb9313f07e86242a51874","ip":"127.0.0.1","user":{"id":0,"name":""}},"runtime":1705839}
  360. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [host]instance-1
  361. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [instance-id]1
  362. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [internal-auth]eyJyb2xlcyI6WyJAaW50ZXJuYWwiXX0=
  363. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-forwarded-for]172.18.0.26
  364. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-remote-ip]172.18.0.26
  365. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Got header: [x-request-id]82398b0b872dd9f585514cc83bc9fb7d
  366. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] RequestBody: {"name":"node_create_finish","output":{"content":"Unhandled exception: node #2 is not in storage ready state","type":"text"},"status":"failed"}
  367. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] End of POST request
  368. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Invoke POST request callback
  369. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] WriterAsyncProcess
  370. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] LimitAssert
  371. vm_1_writer.log:2023-11-21 23:38:34.650 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c02df80 query='SELECT "security_action","ha_cluster_id","ha_id","password_hidden","defer_reason","request_info","node","main_table_name","main_table_id","main_table","output","date_end","date_start","date_create","status","message_params","param","name","consul_id","id" FROM vm_task_log WHERE "consul_id"='81' AND "name"='node_create_finish'' duration=440
  372. vm_1_writer.log:2023-11-21 23:38:34.655 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c02df80 query='UPDATE vm_task_log SET "status"='failed',"date_end"='2023-11-21 23:38:34',"output"='Unhandled exception: node #2 is not in storage ready state' WHERE "id"=14' duration=4206
  373. vm_1_writer.log:2023-11-21 23:38:34.655 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c02df80 query='SELECT id FROM vm_host_log WHERE task='81'' duration=276
  374. vm_1_writer.log:2023-11-21 23:38:34.655 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] db: id=0x7d2f2c02df80 query='SELECT id FROM vm_node_log WHERE task='81'' duration=135
  375. vm_1_writer.log:2023-11-21 23:38:34.656 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Response body '{"id":81}'
  376. vm_1_writer.log:2023-11-21 23:38:34.656 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Writer process duration: 6
  377. vm_1_writer.log:2023-11-21 23:38:34.663 [pid=10703] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@] Notification is created completely
  378. vmctl.log:2023-11-21 23:38:22.766 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got action connect_storages with params
  379. vmctl.log:2023-11-21 23:38:22.766 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Using VmctlMode::VMCTL virt-type kvm
  380. vmctl.log:2023-11-21 23:38:22.767 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Stdin params: {"before_execute":{"last_notify":286},"stdin":{}}
  381. vmctl.log:2023-11-21 23:38:22.767 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Executing action connect_storages with params
  382. vmctl.log:2023-11-21 23:38:22.768 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 10707
  383. vmctl.log:2023-11-21 23:38:22.768 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10707. Execute command: 'scripts/kvm/connect_storages.py '
  384. vmctl.log:2023-11-21 23:38:23.319 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10707. Failed with status 256
  385. vmctl.log:2023-11-21 23:38:23.319 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10707. Output:
  386. vmctl.log:2023-11-21 23:38:23.319 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10707. Error: Traceback (most recent call last):
  387. vmctl.log:2023-11-21 23:38:23.320 [pid=10705] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Unhandled exception: Traceback (most recent call last):
  388. vmctl.log:2023-11-21 23:38:34.609 [pid=10725] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got action node_create_finish with params
  389. vmctl.log:2023-11-21 23:38:34.609 [pid=10725] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Using VmctlMode::VMCTL virt-type kvm
  390. vmctl.log:2023-11-21 23:38:34.610 [pid=10725] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Stdin params: {"before_execute":{"last_notify":286},"stdin":{}}
  391. vmctl.log:2023-11-21 23:38:34.610 [pid=10725] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Executing action node_create_finish with params
  392. vmctl.log:2023-11-21 23:38:34.611 [pid=10725] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalRead service: vm/v3 path: node/2
  393. vmctl.log:2023-11-21 23:38:34.618 [pid=10725] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalCall service: vm path: node/2
  394. vmctl.log:2023-11-21 23:38:34.626 [pid=10725] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Unhandled exception: node #2 is not in storage ready state
  395. root@42c85b6ce222:/var/log#
  396. root@42c85b6ce222:/var/log# grep ecca388e597bb9313f07e86242a51874 node_create/*.log*
  397. node_create/node_2.log:2023-11-21 23:36:55.868 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Got action node_create with params
  398. node_create/node_2.log:2023-11-21 23:36:55.868 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Using VmctlMode::VMCTL virt-type kvm
  399. node_create/node_2.log:2023-11-21 23:36:55.869 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Stdin params: {"before_execute":{"last_notify":286},"stdin":{}}
  400. node_create/node_2.log:2023-11-21 23:36:55.869 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Executing action node_create with params
  401. node_create/node_2.log:2023-11-21 23:36:55.870 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalCall service: nodewatch path: get_node_info
  402. node_create/node_2.log:2023-11-21 23:36:56.385 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] NODE_STAGE: certificate
  403. node_create/node_2.log:2023-11-21 23:36:56.385 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] try to create private key
  404. node_create/node_2.log:2023-11-21 23:36:56.386 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 7658
  405. node_create/node_2.log:2023-11-21 23:36:56.386 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7658. Execute command: '/usr/bin/certtool --generate-privkey > /tmp/d1a8-2718-8d8c-6786-key.pem '
  406. node_create/node_2.log:2023-11-21 23:36:56.578 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7658. Finished successefully with status 0
  407. node_create/node_2.log:2023-11-21 23:36:56.578 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7658. Output:
  408. node_create/node_2.log:2023-11-21 23:36:56.578 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7658. Error: Generating a 3072 bit RSA private key...
  409. node_create/node_2.log:2023-11-21 23:36:56.578 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] generated private key /tmp/d1a8-2718-8d8c-6786-key.pem
  410. node_create/node_2.log:2023-11-21 23:36:56.579 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] try to create certificate
  411. node_create/node_2.log:2023-11-21 23:36:56.579 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 7660
  412. node_create/node_2.log:2023-11-21 23:36:56.579 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7660. Execute command: '/usr/bin/certtool --generate-certificate --template 6416c0407-template --load-privkey /tmp/d1a8-2718-8d8c-6786-key.pem --load-ca-certificate /etc/pki/CA/cacert.pem --load-ca-privkey /opt/ispsystem/vm/etc/vmmgr.pem --outfile /tmp/fde3-7db1-c006-2cdf '
  413. node_create/node_2.log:2023-11-21 23:36:56.588 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7660. Finished successefully with status 0
  414. node_create/node_2.log:2023-11-21 23:36:56.588 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7660. Output:
  415. node_create/node_2.log:2023-11-21 23:36:56.588 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7660. Error: Generating a signed certificate...
  416. node_create/node_2.log:2023-11-21 23:36:56.588 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] generated country=XX
  417. node_create/node_2.log:2023-11-21 23:36:56.588 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] try to create private key
  418. node_create/node_2.log:2023-11-21 23:36:56.589 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 7661
  419. node_create/node_2.log:2023-11-21 23:36:56.589 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7661. Execute command: '/usr/bin/openssl req -newkey rsa:3072 -nodes -keyout /tmp/5132-a277-8169-eb1f-key.pem -out /etc/pki/libvirt/private/client.csr -subj /C=XX/ST=XX/L=XX/O=XX/OU=XX/CN=node@vmmanager '
  420. node_create/node_2.log:2023-11-21 23:36:56.680 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7661. Finished successefully with status 0
  421. node_create/node_2.log:2023-11-21 23:36:56.680 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7661. Output:
  422. node_create/node_2.log:2023-11-21 23:36:56.680 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7661. Error: Generating a RSA private key
  423. node_create/node_2.log:2023-11-21 23:36:56.680 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] generated private key /tmp/5132-a277-8169-eb1f-key.pem
  424. node_create/node_2.log:2023-11-21 23:36:56.680 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] try to create certificate
  425. node_create/node_2.log:2023-11-21 23:36:56.680 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 7662
  426. node_create/node_2.log:2023-11-21 23:36:56.680 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7662. Execute command: '/usr/bin/openssl x509 -req -in /etc/pki/libvirt/private/client.csr -CAkey /opt/ispsystem/vm/etc/vmmgr.pem -CA /etc/pki/CA/cacert.pem -CAcreateserial -days 10950 -extfile openssl_conf -out /tmp/d6d4-a592-7f33-c0d7 '
  427. node_create/node_2.log:2023-11-21 23:36:56.689 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7662. Finished successefully with status 0
  428. node_create/node_2.log:2023-11-21 23:36:56.689 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7662. Output:
  429. node_create/node_2.log:2023-11-21 23:36:56.689 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7662. Error: Signature ok
  430. node_create/node_2.log:2023-11-21 23:36:56.689 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] generated country=XX
  431. node_create/node_2.log:2023-11-21 23:36:56.689 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 7663
  432. node_create/node_2.log:2023-11-21 23:36:56.689 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7663. Execute command: '/usr/bin/ansible-playbook -i 172.31.36.17:22, -e targets=all -e ansible_python_interpreter='auto_silent' -e ca_cert='/etc/pki/CA/cacert.pem' -e server_key='/tmp/d1a8-2718-8d8c-6786-key.pem' -e server_cert='/tmp/fde3-7db1-c006-2cdf' -e client_key='/tmp/5132-a277-8169-eb1f-key.pem' -e client_cert='/tmp/d6d4-a592-7f33-c0d7' -e server_key_dest='/etc/pki/libvirt/private/serverkey.pem' -e server_cert_dest='/etc/pki/libvirt/servercert.pem' -e client_key_dest='/etc/pki/libvirt/private/clientkey.pem' -e client_cert_dest='/etc/pki/libvirt/clientcert.pem' etc/playbooks/node/certificate.yml --timeout 60 -b '
  433. node_create/node_2.log:2023-11-21 23:37:06.043 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7663. Finished successefully with status 0
  434. node_create/node_2.log:2023-11-21 23:37:06.043 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7663. Output:
  435. node_create/node_2.log:2023-11-21 23:37:06.043 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 7663. Error:
  436. node_create/node_2.log:2023-11-21 23:37:06.043 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] process out:
  437. node_create/node_2.log:2023-11-21 23:37:06.043 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] NODE_STAGE: gomon
  438. node_create/node_2.log:2023-11-21 23:37:06.043 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 8202
  439. node_create/node_2.log:2023-11-21 23:37:06.043 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 8202. Execute command: '/usr/bin/ansible-playbook -i 172.31.36.17:22, -e targets=all -e ansible_python_interpreter='auto_silent' -e datacenter_type='common' -e is_lxd='0' -e closed_contour='0' etc/playbooks/node/gomon.yml --timeout 60 -b '
  440. node_create/node_2.log:2023-11-21 23:37:14.157 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 8202. Finished successefully with status 0
  441. node_create/node_2.log:2023-11-21 23:37:14.157 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 8202. Output:
  442. node_create/node_2.log:2023-11-21 23:37:14.157 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 8202. Error: [WARNING]: Templating the path of the parent include_tasks failed. The path to
  443. node_create/node_2.log:2023-11-21 23:37:14.157 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] process out:
  444. node_create/node_2.log:2023-11-21 23:37:14.157 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalCall service: nodewatch path: install_gomon/2
  445. node_create/node_2.log:2023-11-21 23:37:14.308 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] NODE_STAGE: prepare
  446. node_create/node_2.log:2023-11-21 23:37:14.308 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 8392
  447. node_create/node_2.log:2023-11-21 23:37:14.308 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 8392. Execute command: '/usr/bin/ansible-playbook -i 172.31.36.17:22, -e targets=all -e ansible_python_interpreter='auto_silent' -e timezone='UTC' -e os_storage_path='/share' -e image_storage_path='/image' -e datacenter_type='common' -e is_lxd='0' -e closed_contour='0' etc/playbooks/node/prepare.yml --timeout 60 -b '
  448. node_create/node_2.log:2023-11-21 23:37:36.012 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 8392. Finished successefully with status 0
  449. node_create/node_2.log:2023-11-21 23:37:36.012 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 8392. Output:
  450. node_create/node_2.log:2023-11-21 23:37:36.012 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 8392. Error: [WARNING]: Templating the path of the parent include_tasks failed. The path to
  451. node_create/node_2.log:2023-11-21 23:37:36.012 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] process out:
  452. node_create/node_2.log:2023-11-21 23:37:36.012 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] NODE_STAGE: firewall
  453. node_create/node_2.log:2023-11-21 23:37:36.013 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 9259
  454. node_create/node_2.log:2023-11-21 23:37:36.013 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 9259. Execute command: '/usr/bin/ansible-playbook -i 172.31.36.17:22, -e targets=all -e ansible_python_interpreter='auto_silent' -e datacenter_type='common' -e ssh_port='22' -e network_autosetup_enabled='1' -e is_lxd='0' -e dc_ips='' -e dc_ips6='' -e closed_contour='0' etc/playbooks/node/firewall.yml --timeout 60 -b '
  455. node_create/node_2.log:2023-11-21 23:37:55.498 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 9259. Finished successefully with status 0
  456. node_create/node_2.log:2023-11-21 23:37:55.498 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 9259. Output:
  457. node_create/node_2.log:2023-11-21 23:37:55.498 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 9259. Error: [WARNING]: Templating the path of the parent include_tasks failed. The path to
  458. node_create/node_2.log:2023-11-21 23:37:55.498 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] process out:
  459. node_create/node_2.log:2023-11-21 23:37:55.498 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalRead service: vm/v3 path: node/2
  460. node_create/node_2.log:2023-11-21 23:37:55.504 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalCall service: vm path: node/2
  461. node_create/node_2.log:2023-11-21 23:37:55.617 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] NODE_STAGE: libvirtd
  462. node_create/node_2.log:2023-11-21 23:37:55.617 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 10168
  463. node_create/node_2.log:2023-11-21 23:37:55.618 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10168. Execute command: '/usr/bin/ansible-playbook -i 172.31.36.17:22, -e targets=all -e ansible_python_interpreter='auto_silent' -e node_ip='172.31.36.17' -e is_lxd='0' -e node_id='2' -e closed_contour='0' etc/playbooks/node/virt.yml --timeout 60 -b '
  464. node_create/node_2.log:2023-11-21 23:38:14.101 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10168. Finished successefully with status 0
  465. node_create/node_2.log:2023-11-21 23:38:14.101 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10168. Output:
  466. node_create/node_2.log:2023-11-21 23:38:14.101 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10168. Error: [WARNING]: Templating the path of the parent include_tasks failed. The path to
  467. node_create/node_2.log:2023-11-21 23:38:14.101 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] process out:
  468. node_create/node_2.log:2023-11-21 23:38:14.101 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] NODE_STAGE: network
  469. node_create/node_2.log:2023-11-21 23:38:14.101 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Fork. New Process PID: 10678
  470. node_create/node_2.log:2023-11-21 23:38:14.101 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10678. Execute command: 'scripts/node_network/node_network_astra_1.7.py --datacenter_type common --node_id 2 '
  471. node_create/node_2.log:2023-11-21 23:38:22.245 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10678. Finished successefully with status 0
  472. node_create/node_2.log:2023-11-21 23:38:22.245 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10678. Output: {"started": true, "error": "failed to configure network, changes have been reverted", "reverted": true}{"started": true, "error": "failed to configure network, changes have been reverted", "reverted": true}
  473. node_create/node_2.log:2023-11-21 23:38:22.245 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] PID: 10678. Error:
  474. node_create/node_2.log:2023-11-21 23:38:22.245 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] process out: {"started": true, "error": "failed to configure network, changes have been reverted", "reverted": true}{"started": true, "error": "failed to configure network, changes have been reverted", "reverted": true}
  475. node_create/node_2.log:2023-11-21 23:38:22.245 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com]
  476. node_create/node_2.log:2023-11-21 23:38:22.245 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com]
  477. node_create/node_2.log:2023-11-21 23:38:22.246 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] error: failed to parse script output: '{"started": true, "error": "failed to configure network, changes have been reverted", "reverted": true}{"started": true, "error": "failed to configure network, changes have been reverted", "reverted": true}'
  478. node_create/node_2.log:2023-11-21 23:38:22.246 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalRead service: vm/v3 path: node/2
  479. node_create/node_2.log:2023-11-21 23:38:22.251 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] InternalCall service: vm path: node/2
  480. node_create/node_2.log:2023-11-21 23:38:22.350 [pid=7655] [#ecca388e597bb9313f07e86242a51874/127.0.0.1/@n.mamaev@ispsystem.com] Unhandled exception: failed to parse script output: '{"started": true, "error": "failed to configure network, changes have been reverted", "reverted": true}{"started": true, "error": "failed to configure network, changes have been reverted", "reverted": true}'
Advertisement
Add Comment
Please, Sign In to add comment
Advertisement
Public Pastes
Advertisement
We use cookies for various purposes including analytics. By continuing to use Pastebin, you agree to our use of cookies as described in the Cookies Policy.  OK, I Understand
Not a member of Pastebin yet?
Sign Up, it unlocks many cool features!