[ OST Failure Report ] [ ovirt-engine-4.1 ] [ 02.03.2017 ] [004_basic_sanity]
Hi, This is one-time failure. Non reproducible. disk_id was not inserted into DB because of jsonrpc/networking issue. But once OST runs on localhost networking (should not) be a problem here so adding Piotr. Failed jobs: http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi... Logs: http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi... http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi... [LOGS SNIPPETS] 35897:2017-03-02 07:12:28,721-05 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (default task-19) [4adab878] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), log id: 657ef611 35920:{"jsonrpc":"2.0","method":"Volume.create","params":{"volumeID":"c5275e2f-ac80-47c2-a43e-b5a0420a4211","storagepoolID":"9314c679-9a20-48b4-b62a-f7b6a3703287","storagedomainID":"49226db8-e43f-4a15-a3a3-0bddd690d06b","imageID":"9cf5a90d-05fc-45de-a3c1-adbb6822150e","size":"2","volFormat":4,"preallocate":2,"diskType":2,"desc":"{\"DiskAlias\":\"vm0_disk0\",\"DiskDescription\":\"\"}","srcImgUUID":"00000000-0000-0000-0000-000000000000","srcVolUUID":"00000000-0000-0000-0000-000000000000"},"id":"0a757eae-0cc2-4f15-9bb5-05ad3221f697"} <=== NOTE NULL character here 35926:<JsonRpcRequest id: "0a757eae-0cc2-4f15-9bb5-05ad3221f697", method: Volume.create, params: {volumeID=c5275e2f-ac80-47c2-a43e-b5a0420a4211, storagepoolID=9314c679-9a20-48b4-b62a-f7b6a3703287, storagedomainID=49226db8-e43f-4a15-a3a3-0bddd690d06b, imageID=9cf5a90d-05fc-45de-a3c1-adbb6822150e, size=2, volFormat=4, preallocate=2, diskType=2, desc={"DiskAlias":"vm0_disk0","DiskDescription":""}, srcImgUUID=00000000-0000-0000-0000-000000000000, srcVolUUID=00000000-0000-0000-0000-000000000000}> 35996:2017-03-02 07:12:30,468-05 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (default task-19) [4adab878] ERROR, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), exception: VDSGenericException: VDSNetworkException: 880 > 879, log id: 657ef611 36511:2017-03-02 07:12:35,744-05 INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (default task-19) [4adab878] Command [id=35007fba-781c-4a15-8f29-a8efe441b2f3]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.storage.DiskImage; snapshot: 9cf5a90d-05fc-45de-a3c1-adbb6822150e. 2017-03-02 07:12:35,766-05 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler7) [6dc0e793] EVENT_ID: SYSTEM_CHANGE_STORAGE_POOL_STATUS_PROBLEMATIC(980), Correlation ID: 6dc0e793, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center test-dc. Setting status to Non Responsive. 2017-03-02 07:12:35,773-05 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-19) [4adab878] Removed task '10b3bd58-8f3e-4b23-a8b6-27db110810d5' from DataBase 2017-03-02 07:12:35,779-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.CustomSQLErrorCodeSQLExceptionTranslator] (default task-19) [4adab878] Translating SQLException with SQL state '23503', error code '0', message [ERROR: insert or update on table "disk_vm_element" violates foreign key constraint "fk_disk_vm_element_base_disks" Detail: Key (disk_id)=(9cf5a90d-05fc-45de-a3c1-adbb6822150e) is not present in table "base_disks". -- Pavel
This bug [1] is already fixed but not yet backported to 4.1. I want to make sure that there is no regressions on master. Hopefully I will push it on Monday. Thanks, Piotr [1] https://bugzilla.redhat.com/1425725 On Fri, Mar 3, 2017 at 8:53 AM, Pavel Zhukov <pzhukov@redhat.com> wrote:
Hi,
This is one-time failure. Non reproducible. disk_id was not inserted into DB because of jsonrpc/networking issue. But once OST runs on localhost networking (should not) be a problem here so adding Piotr.
Failed jobs: http://jenkins.ovirt.org/view/experimental%20jobs/job/test- repo_ovirt_experimental_4.1/845/
Logs: http://jenkins.ovirt.org/view/experimental%20jobs/job/test- repo_ovirt_experimental_4.1/845/artifact/exported-artifacts http://jenkins.ovirt.org/view/experimental%20jobs/job/test- repo_ovirt_experimental_4.1/845/artifact/*zip*/archive.zip
[LOGS SNIPPETS]
35897:2017-03-02 07:12:28,721-05 INFO [org.ovirt.engine.core. vdsbroker.irsbroker.CreateImageVDSCommand] (default task-19) [4adab878] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), log id: 657ef611 35920:{"jsonrpc":"2.0","method":"Volume.create"," params":{"volumeID":"c5275e2f-ac80-47c2-a43e-b5a0420a4211"," storagepoolID":"9314c679-9a20-48b4-b62a-f7b6a3703287"," storagedomainID":"49226db8-e43f-4a15-a3a3-0bddd690d06b"," imageID":"9cf5a90d-05fc-45de-a3c1-adbb6822150e","size":"2", "volFormat":4,"preallocate":2,"diskType":2,"desc":"{\" DiskAlias\":\"vm0_disk0\",\"DiskDescription\":\"\"}"," srcImgUUID":"00000000-0000-0000-0000-000000000000"," srcVolUUID":"00000000-0000-0000-0000-000000000000"},"id": "0a757eae-0cc2-4f15-9bb5-05ad3221f697"} <=== NOTE NULL character here 35926:<JsonRpcRequest id: "0a757eae-0cc2-4f15-9bb5-05ad3221f697", method: Volume.create, params: {volumeID=c5275e2f-ac80-47c2-a43e-b5a0420a4211, storagepoolID=9314c679-9a20-48b4-b62a-f7b6a3703287, storagedomainID=49226db8-e43f-4a15-a3a3-0bddd690d06b, imageID=9cf5a90d-05fc-45de-a3c1-adbb6822150e, size=2, volFormat=4, preallocate=2, diskType=2, desc={"DiskAlias":"vm0_disk0","DiskDescription":""}, srcImgUUID=00000000-0000-0000-0000-000000000000, srcVolUUID=00000000-0000-0000-0000-000000000000}> 35996:2017-03-02 07:12:30,468-05 ERROR [org.ovirt.engine.core. vdsbroker.irsbroker.IrsBrokerCommand] (default task-19) [4adab878] ERROR, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), exception: VDSGenericException: VDSNetworkException: 880 > 879, log id: 657ef611 36511:2017-03-02 07:12:35,744-05 INFO [org.ovirt.engine.core.bll. storage.disk.image.AddImageFromScratchCommand] (default task-19) [4adab878] Command [id=35007fba-781c-4a15-8f29-a8efe441b2f3]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common. businessentities.storage.DiskImage; snapshot: 9cf5a90d-05fc-45de-a3c1- adbb6822150e. 2017-03-02 07:12:35,766-05 WARN [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler7) [6dc0e793] EVENT_ID: SYSTEM_CHANGE_STORAGE_POOL_STATUS_PROBLEMATIC(980), Correlation ID: 6dc0e793, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center test-dc. Setting status to Non Responsive. 2017-03-02 07:12:35,773-05 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-19) [4adab878] Removed task '10b3bd58-8f3e-4b23-a8b6-27db110810d5' from DataBase 2017-03-02 07:12:35,779-05 DEBUG [org.ovirt.engine.core.dal.dbbroker. CustomSQLErrorCodeSQLExceptionTranslator] (default task-19) [4adab878] Translating SQLException with SQL state '23503', error code '0', message [ERROR: insert or update on table "disk_vm_element" violates foreign key constraint "fk_disk_vm_element_base_disks" Detail: Key (disk_id)=(9cf5a90d-05fc-45de-a3c1-adbb6822150e) is not present in table "base_disks".
-- Pavel
Just had this failure again[1], relevant log[2]. I still feel there's an issue here: {"jsonrpc": "2.0", "id": "aa241c36-d61d-4f9f-9baf-040b00638d00", "result": [{"username": "Unknown", "displayInfo": [{"tlsPort": "-1", "ipAddress": "192.168.201.4", "type": "vnc", "port": "5900"}, {"tlsPort": "5901", "ipAddress": "192.168.201.4", "type": "spice", "port": "-1"}], "hash": "964568653906073065", "acpiEnable": "true", "displayIp": "192.168.201.4", "guestFQDN": "", "vmId": "c9db9f94-3086-47e4-b997-01564ecb5319", "pid": "23127", "timeOffset": "0", "session": "Unknown", "displaySecurePort": "-1", "displayPort": "5900", "memUsage": "0", "guestIPs": "", "vcpuQuota": "-1", "kvmEnable": "true", "displayType": "vnc", "cpuUser": "0.00", "vmJobs": {}, "monitorResponse": "0", "elapsedTime": "477", "vmType": "kvm", "cpuSys": "0.00", "status": "Up", "guestCPUCount": -1, "appsList": [], "clientIp": "", "statusTime": "4295847140", "vmName": "vm0", "vcpuPeriod": 100000}]} 2017-03-16 10:36:17,558-04 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.Reactor] (SSL Stomp Reactor) [cb68faa] Internal server error 880 > 879: java.lang.IllegalArgumentException: 880 > 879 at java.util.Arrays.copyOfRange(Arrays.java:3519) [rt.jar:1.8.0_121] at org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient.processIncoming(StompCommonClient.java:145) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.process(ReactorClient.java:195) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.SSLClient.process(SSLClient.java:121) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.lambda$processChannels$2(Reactor.java:80) [vdsm-jsonrpc-java-client.jar:] Y. [1] http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86_6... [2] http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86_6... On Fri, Mar 3, 2017 at 9:53 AM, Pavel Zhukov <pzhukov@redhat.com> wrote:
Hi,
This is one-time failure. Non reproducible. disk_id was not inserted into DB because of jsonrpc/networking issue. But once OST runs on localhost networking (should not) be a problem here so adding Piotr.
Failed jobs: http://jenkins.ovirt.org/view/experimental%20jobs/job/test- repo_ovirt_experimental_4.1/845/
Logs: http://jenkins.ovirt.org/view/experimental%20jobs/job/test- repo_ovirt_experimental_4.1/845/artifact/exported-artifacts http://jenkins.ovirt.org/view/experimental%20jobs/job/test- repo_ovirt_experimental_4.1/845/artifact/*zip*/archive.zip
[LOGS SNIPPETS]
35897:2017-03-02 07:12:28,721-05 INFO [org.ovirt.engine.core. vdsbroker.irsbroker.CreateImageVDSCommand] (default task-19) [4adab878] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), log id: 657ef611 35920:{"jsonrpc":"2.0","method":"Volume.create"," params":{"volumeID":"c5275e2f-ac80-47c2-a43e-b5a0420a4211"," storagepoolID":"9314c679-9a20-48b4-b62a-f7b6a3703287"," storagedomainID":"49226db8-e43f-4a15-a3a3-0bddd690d06b"," imageID":"9cf5a90d-05fc-45de-a3c1-adbb6822150e","size":"2", "volFormat":4,"preallocate":2,"diskType":2,"desc":"{\" DiskAlias\":\"vm0_disk0\",\"DiskDescription\":\"\"}"," srcImgUUID":"00000000-0000-0000-0000-000000000000"," srcVolUUID":"00000000-0000-0000-0000-000000000000"},"id": "0a757eae-0cc2-4f15-9bb5-05ad3221f697"} <=== NOTE NULL character here 35926:<JsonRpcRequest id: "0a757eae-0cc2-4f15-9bb5-05ad3221f697", method: Volume.create, params: {volumeID=c5275e2f-ac80-47c2-a43e-b5a0420a4211, storagepoolID=9314c679-9a20-48b4-b62a-f7b6a3703287, storagedomainID=49226db8-e43f-4a15-a3a3-0bddd690d06b, imageID=9cf5a90d-05fc-45de-a3c1-adbb6822150e, size=2, volFormat=4, preallocate=2, diskType=2, desc={"DiskAlias":"vm0_disk0","DiskDescription":""}, srcImgUUID=00000000-0000-0000-0000-000000000000, srcVolUUID=00000000-0000-0000-0000-000000000000}> 35996:2017-03-02 07:12:30,468-05 ERROR [org.ovirt.engine.core. vdsbroker.irsbroker.IrsBrokerCommand] (default task-19) [4adab878] ERROR, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), exception: VDSGenericException: VDSNetworkException: 880 > 879, log id: 657ef611 36511:2017-03-02 07:12:35,744-05 INFO [org.ovirt.engine.core.bll. storage.disk.image.AddImageFromScratchCommand] (default task-19) [4adab878] Command [id=35007fba-781c-4a15-8f29-a8efe441b2f3]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common. businessentities.storage.DiskImage; snapshot: 9cf5a90d-05fc-45de-a3c1- adbb6822150e. 2017-03-02 07:12:35,766-05 WARN [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler7) [6dc0e793] EVENT_ID: SYSTEM_CHANGE_STORAGE_POOL_STATUS_PROBLEMATIC(980), Correlation ID: 6dc0e793, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center test-dc. Setting status to Non Responsive. 2017-03-02 07:12:35,773-05 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-19) [4adab878] Removed task '10b3bd58-8f3e-4b23-a8b6-27db110810d5' from DataBase 2017-03-02 07:12:35,779-05 DEBUG [org.ovirt.engine.core.dal.dbbroker. CustomSQLErrorCodeSQLExceptionTranslator] (default task-19) [4adab878] Translating SQLException with SQL state '23503', error code '0', message [ERROR: insert or update on table "disk_vm_element" violates foreign key constraint "fk_disk_vm_element_base_disks" Detail: Key (disk_id)=(9cf5a90d-05fc-45de-a3c1-adbb6822150e) is not present in table "base_disks".
-- Pavel _______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
I checked the logs and I checked that the job somehow used older version without the fix: 2017-03-16 14:16:07,212::INFO::repoman.common.stores.RPM::Adding package /var/lib/lago/reposync/ovirt-4.1-el7/noarch/vdsm-jsonrpc-java-1.3.8-1.el7.centos.noarch.rpm to repo /dev/shm/ost/deployment-basic-suite-4.1/default/internal_repo How is it possible? On Thu, Mar 16, 2017 at 4:30 PM, Yaniv Kaul <ykaul@redhat.com> wrote:
Just had this failure again[1], relevant log[2].
I still feel there's an issue here: {"jsonrpc": "2.0", "id": "aa241c36-d61d-4f9f-9baf-040b00638d00", "result": [{"username": "Unknown", "displayInfo": [{"tlsPort": "-1", "ipAddress": "192.168.201.4", "type": "vnc", "port": "5900"}, {"tlsPort": "5901", "ipAddress": "192.168.201.4", "type": "spice", "port": "-1"}], "hash": "964568653906073065", "acpiEnable": "true", "displayIp": "192.168.201.4", "guestFQDN": "", "vmId": "c9db9f94-3086-47e4-b997-01564ecb5319", "pid": "23127", "timeOffset": "0", "session": "Unknown", "displaySecurePort": "-1", "displayPort": "5900", "memUsage": "0", "guestIPs": "", "vcpuQuota": "-1", "kvmEnable": "true", "displayType": "vnc", "cpuUser": "0.00", "vmJobs": {}, "monitorResponse": "0", "elapsedTime": "477", "vmType": "kvm", "cpuSys": "0.00", "status": "Up", "guestCPUCount": -1, "appsList": [], "clientIp": "", "statusTime": "4295847140", "vmName": "vm0", "vcpuPeriod": 100000}]} 2017-03-16 10:36:17,558-04 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.Reactor] (SSL Stomp Reactor) [cb68faa] Internal server error 880 > 879: java.lang.IllegalArgumentException: 880 > 879 at java.util.Arrays.copyOfRange(Arrays.java:3519) [rt.jar:1.8.0_121] at org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient.processIncoming(StompCommonClient.java:145) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.process(ReactorClient.java:195) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.SSLClient.process(SSLClient.java:121) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.lambda$processChannels$2(Reactor.java:80) [vdsm-jsonrpc-java-client.jar:]
Y.
[1] http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86_6... [2] http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86_6...
On Fri, Mar 3, 2017 at 9:53 AM, Pavel Zhukov <pzhukov@redhat.com> wrote:
Hi,
This is one-time failure. Non reproducible. disk_id was not inserted into DB because of jsonrpc/networking issue. But once OST runs on localhost networking (should not) be a problem here so adding Piotr.
Failed jobs:
http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi...
Logs:
http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi...
http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi...
[LOGS SNIPPETS]
35897:2017-03-02 07:12:28,721-05 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (default task-19) [4adab878] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), log id: 657ef611
35920:{"jsonrpc":"2.0","method":"Volume.create","params":{"volumeID":"c5275e2f-ac80-47c2-a43e-b5a0420a4211","storagepoolID":"9314c679-9a20-48b4-b62a-f7b6a3703287","storagedomainID":"49226db8-e43f-4a15-a3a3-0bddd690d06b","imageID":"9cf5a90d-05fc-45de-a3c1-adbb6822150e","size":"2","volFormat":4,"preallocate":2,"diskType":2,"desc":"{\"DiskAlias\":\"vm0_disk0\",\"DiskDescription\":\"\"}","srcImgUUID":"00000000-0000-0000-0000-000000000000","srcVolUUID":"00000000-0000-0000-0000-000000000000"},"id":"0a757eae-0cc2-4f15-9bb5-05ad3221f697"} <=== NOTE NULL character here 35926:<JsonRpcRequest id: "0a757eae-0cc2-4f15-9bb5-05ad3221f697", method: Volume.create, params: {volumeID=c5275e2f-ac80-47c2-a43e-b5a0420a4211, storagepoolID=9314c679-9a20-48b4-b62a-f7b6a3703287, storagedomainID=49226db8-e43f-4a15-a3a3-0bddd690d06b, imageID=9cf5a90d-05fc-45de-a3c1-adbb6822150e, size=2, volFormat=4, preallocate=2, diskType=2, desc={"DiskAlias":"vm0_disk0","DiskDescription":""}, srcImgUUID=00000000-0000-0000-0000-000000000000, srcVolUUID=00000000-0000-0000-0000-000000000000}> 35996:2017-03-02 07:12:30,468-05 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (default task-19) [4adab878] ERROR, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), exception: VDSGenericException: VDSNetworkException: 880 > 879, log id: 657ef611 36511:2017-03-02 07:12:35,744-05 INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (default task-19) [4adab878] Command [id=35007fba-781c-4a15-8f29-a8efe441b2f3]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.storage.DiskImage; snapshot: 9cf5a90d-05fc-45de-a3c1-adbb6822150e. 2017-03-02 07:12:35,766-05 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler7) [6dc0e793] EVENT_ID: SYSTEM_CHANGE_STORAGE_POOL_STATUS_PROBLEMATIC(980), Correlation ID: 6dc0e793, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center test-dc. Setting status to Non Responsive. 2017-03-02 07:12:35,773-05 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-19) [4adab878] Removed task '10b3bd58-8f3e-4b23-a8b6-27db110810d5' from DataBase 2017-03-02 07:12:35,779-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.CustomSQLErrorCodeSQLExceptionTranslator] (default task-19) [4adab878] Translating SQLException with SQL state '23503', error code '0', message [ERROR: insert or update on table "disk_vm_element" violates foreign key constraint "fk_disk_vm_element_base_disks" Detail: Key (disk_id)=(9cf5a90d-05fc-45de-a3c1-adbb6822150e) is not present in table "base_disks".
-- Pavel _______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
_______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
+ infra On Thu, Mar 16, 2017 at 5:32 PM, Piotr Kliczewski <piotr.kliczewski@gmail.com> wrote:
I checked the logs and I checked that the job somehow used older version without the fix:
2017-03-16 14:16:07,212::INFO::repoman.common.stores.RPM::Adding package /var/lib/lago/reposync/ovirt-4.1-el7/noarch/vdsm-jsonrpc-java-1.3.8-1.el7.centos.noarch.rpm to repo /dev/shm/ost/deployment-basic-suite-4.1/default/internal_repo
How is it possible?
On Thu, Mar 16, 2017 at 4:30 PM, Yaniv Kaul <ykaul@redhat.com> wrote:
Just had this failure again[1], relevant log[2].
I still feel there's an issue here: {"jsonrpc": "2.0", "id": "aa241c36-d61d-4f9f-9baf-040b00638d00", "result": [{"username": "Unknown", "displayInfo": [{"tlsPort": "-1", "ipAddress": "192.168.201.4", "type": "vnc", "port": "5900"}, {"tlsPort": "5901", "ipAddress": "192.168.201.4", "type": "spice", "port": "-1"}], "hash": "964568653906073065", "acpiEnable": "true", "displayIp": "192.168.201.4", "guestFQDN": "", "vmId": "c9db9f94-3086-47e4-b997-01564ecb5319", "pid": "23127", "timeOffset": "0", "session": "Unknown", "displaySecurePort": "-1", "displayPort": "5900", "memUsage": "0", "guestIPs": "", "vcpuQuota": "-1", "kvmEnable": "true", "displayType": "vnc", "cpuUser": "0.00", "vmJobs": {}, "monitorResponse": "0", "elapsedTime": "477", "vmType": "kvm", "cpuSys": "0.00", "status": "Up", "guestCPUCount": -1, "appsList": [], "clientIp": "", "statusTime": "4295847140", "vmName": "vm0", "vcpuPeriod": 100000}]} 2017-03-16 10:36:17,558-04 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.Reactor] (SSL Stomp Reactor) [cb68faa] Internal server error 880 > 879: java.lang.IllegalArgumentException: 880 > 879 at java.util.Arrays.copyOfRange(Arrays.java:3519) [rt.jar:1.8.0_121] at org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient.processIncoming(StompCommonClient.java:145) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.process(ReactorClient.java:195) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.SSLClient.process(SSLClient.java:121) [vdsm-jsonrpc-java-client.jar:] at org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.lambda$processChannels$2(Reactor.java:80) [vdsm-jsonrpc-java-client.jar:]
Y.
[1] http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86_6... [2] http://jenkins.ovirt.org/job/ovirt-system-tests_master_check-patch-el7-x86_6...
On Fri, Mar 3, 2017 at 9:53 AM, Pavel Zhukov <pzhukov@redhat.com> wrote:
Hi,
This is one-time failure. Non reproducible. disk_id was not inserted into DB because of jsonrpc/networking issue. But once OST runs on localhost networking (should not) be a problem here so adding Piotr.
Failed jobs:
http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi...
Logs:
http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi...
http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experi...
[LOGS SNIPPETS]
35897:2017-03-02 07:12:28,721-05 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateImageVDSCommand] (default task-19) [4adab878] START, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), log id: 657ef611
35920:{"jsonrpc":"2.0","method":"Volume.create","params":{"volumeID":"c5275e2f-ac80-47c2-a43e-b5a0420a4211","storagepoolID":"9314c679-9a20-48b4-b62a-f7b6a3703287","storagedomainID":"49226db8-e43f-4a15-a3a3-0bddd690d06b","imageID":"9cf5a90d-05fc-45de-a3c1-adbb6822150e","size":"2","volFormat":4,"preallocate":2,"diskType":2,"desc":"{\"DiskAlias\":\"vm0_disk0\",\"DiskDescription\":\"\"}","srcImgUUID":"00000000-0000-0000-0000-000000000000","srcVolUUID":"00000000-0000-0000-0000-000000000000"},"id":"0a757eae-0cc2-4f15-9bb5-05ad3221f697"} <=== NOTE NULL character here 35926:<JsonRpcRequest id: "0a757eae-0cc2-4f15-9bb5-05ad3221f697", method: Volume.create, params: {volumeID=c5275e2f-ac80-47c2-a43e-b5a0420a4211, storagepoolID=9314c679-9a20-48b4-b62a-f7b6a3703287, storagedomainID=49226db8-e43f-4a15-a3a3-0bddd690d06b, imageID=9cf5a90d-05fc-45de-a3c1-adbb6822150e, size=2, volFormat=4, preallocate=2, diskType=2, desc={"DiskAlias":"vm0_disk0","DiskDescription":""}, srcImgUUID=00000000-0000-0000-0000-000000000000, srcVolUUID=00000000-0000-0000-0000-000000000000}> 35996:2017-03-02 07:12:30,468-05 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (default task-19) [4adab878] ERROR, CreateImageVDSCommand( CreateImageVDSCommandParameters:{runAsync='true', storagePoolId='9314c679-9a20-48b4-b62a-f7b6a3703287', ignoreFailoverLimit='false', storageDomainId='49226db8-e43f-4a15-a3a3-0bddd690d06b', imageGroupId='9cf5a90d-05fc-45de-a3c1-adbb6822150e', imageSizeInBytes='2', volumeFormat='COW', newImageId='c5275e2f-ac80-47c2-a43e-b5a0420a4211', newImageDescription='{"DiskAlias":"vm0_disk0","DiskDescription":""}', imageInitialSizeInBytes='0'}), exception: VDSGenericException: VDSNetworkException: 880 > 879, log id: 657ef611 36511:2017-03-02 07:12:35,744-05 INFO [org.ovirt.engine.core.bll.storage.disk.image.AddImageFromScratchCommand] (default task-19) [4adab878] Command [id=35007fba-781c-4a15-8f29-a8efe441b2f3]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.storage.DiskImage; snapshot: 9cf5a90d-05fc-45de-a3c1-adbb6822150e. 2017-03-02 07:12:35,766-05 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler7) [6dc0e793] EVENT_ID: SYSTEM_CHANGE_STORAGE_POOL_STATUS_PROBLEMATIC(980), Correlation ID: 6dc0e793, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center test-dc. Setting status to Non Responsive. 2017-03-02 07:12:35,773-05 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-19) [4adab878] Removed task '10b3bd58-8f3e-4b23-a8b6-27db110810d5' from DataBase 2017-03-02 07:12:35,779-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.CustomSQLErrorCodeSQLExceptionTranslator] (default task-19) [4adab878] Translating SQLException with SQL state '23503', error code '0', message [ERROR: insert or update on table "disk_vm_element" violates foreign key constraint "fk_disk_vm_element_base_disks" Detail: Key (disk_id)=(9cf5a90d-05fc-45de-a3c1-adbb6822150e) is not present in table "base_disks".
-- Pavel _______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
_______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
On 16 March 2017 at 18:33, Piotr Kliczewski <piotr.kliczewski@gmail.com> wrote:
+ infra
On Thu, Mar 16, 2017 at 5:32 PM, Piotr Kliczewski <piotr.kliczewski@gmail.com> wrote:
I checked the logs and I checked that the job somehow used older version without the fix:
2017-03-16 14:16:07,212::INFO::repoman.common.stores.RPM::Adding package /var/lib/lago/reposync/ovirt-4.1-el7/noarch/vdsm-jsonrpc-java-1.3.8-1.el7.centos.noarch.rpm to repo /dev/shm/ost/deployment-basic-suite-4.1/default/internal_repo
How is it possible?
The "experimental" OST flow runs against the experimental repo that includes the latest built packages from all projects. A vanilla clone of OST, as well as the OST check-patch job, run against the official released repos. I guess the fixed version did not make it to a release yet. By the way, when reading the repoman log, the important lines are the ones that start with "Saving". The lines with "Adding" just show the packages it "sees" not the ones it eventually decides to expose to the VMs. -- Barak Korren bkorren@redhat.com RHCE, RHCi, RHV-DevOps Team https://ifireball.wordpress.com/
On Fri, Mar 17, 2017 at 8:24 AM, Barak Korren <bkorren@redhat.com> wrote:
On 16 March 2017 at 18:33, Piotr Kliczewski <piotr.kliczewski@gmail.com> wrote:
+ infra
On Thu, Mar 16, 2017 at 5:32 PM, Piotr Kliczewski <piotr.kliczewski@gmail.com> wrote:
I checked the logs and I checked that the job somehow used older version without the fix:
2017-03-16 14:16:07,212::INFO::repoman.common.stores.RPM::Adding package /var/lib/lago/reposync/ovirt-4.1-el7/noarch/vdsm-jsonrpc-java-1.3.8-1.el7.centos.noarch.rpm to repo /dev/shm/ost/deployment-basic-suite-4.1/default/internal_repo
How is it possible?
The "experimental" OST flow runs against the experimental repo that includes the latest built packages from all projects. A vanilla clone of OST, as well as the OST check-patch job, run against the official released repos. I guess the fixed version did not make it to a release yet.
The change was merged 2 weeks ago. How can we make sure not to waste people time next time to analyze the issue?
By the way, when reading the repoman log, the important lines are the ones that start with "Saving". The lines with "Adding" just show the packages it "sees" not the ones it eventually decides to expose to the VMs.
-- Barak Korren bkorren@redhat.com RHCE, RHCi, RHV-DevOps Team https://ifireball.wordpress.com/
בתאריך 17 במרץ 2017 02:32 PM, "Piotr Kliczewski" < piotr.kliczewski@gmail.com> כתב: The change was merged 2 weeks ago. How can we make sure not to waste people time next time to analyze the issue? "Merged" is hardly "released". As long as a fix does not make it to a release, users can still come across the issue, and so can OST. I can't think of a quick way to avoid that, but I'm open to suggestions.... WRT getting more frequent oVirt releases, I'm hardly in a position to give input about that.
As Piotr mentioned, the job is using 1.3.8 however 1.3.9 was released..... On Sun, Mar 19, 2017 at 10:27 AM, Barak Korren <bkorren@redhat.com> wrote:
בתאריך 17 במרץ 2017 02:32 PM, "Piotr Kliczewski" < piotr.kliczewski@gmail.com> כתב:
The change was merged 2 weeks ago. How can we make sure not to waste people time next time to analyze the issue?
"Merged" is hardly "released".
As long as a fix does not make it to a release, users can still come across the issue, and so can OST. I can't think of a quick way to avoid that, but I'm open to suggestions....
WRT getting more frequent oVirt releases, I'm hardly in a position to give input about that.
_______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
On Sun, Mar 19, 2017 at 10:30 AM, Oved Ourfali <oourfali@redhat.com> wrote:
As Piotr mentioned, the job is using 1.3.8 however 1.3.9 was released.....
Thanks, We will look into the logs and find out what caused it to use 1.3.8 and report here on the results, can't be sure yet if its a bug in the job or anything else.
On Sun, Mar 19, 2017 at 10:27 AM, Barak Korren <bkorren@redhat.com> wrote:
בתאריך 17 במרץ 2017 02:32 PM, "Piotr Kliczewski" < piotr.kliczewski@gmail.com> כתב:
The change was merged 2 weeks ago. How can we make sure not to waste people time next time to analyze the issue?
"Merged" is hardly "released".
As long as a fix does not make it to a release, users can still come across the issue, and so can OST. I can't think of a quick way to avoid that, but I'm open to suggestions....
WRT getting more frequent oVirt releases, I'm hardly in a position to give input about that.
_______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
_______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
-- Eyal Edri Associate Manager RHV DevOps EMEA ENG Virtualization R&D Red Hat Israel phone: +972-9-7692018 irc: eedri (on #tlv #rhev-dev #rhev-integ)
On Sun, Mar 19, 2017 at 10:33 AM, Eyal Edri <eedri@redhat.com> wrote:
On Sun, Mar 19, 2017 at 10:30 AM, Oved Ourfali <oourfali@redhat.com> wrote:
As Piotr mentioned, the job is using 1.3.8 however 1.3.9 was released.....
Thanks, We will look into the logs and find out what caused it to use 1.3.8 and report here on the results, can't be sure yet if its a bug in the job or anything else.
Let me explain what happened: 1. check-patch jobs used to run on latest 'tested' repo, but that repo is very big as it contains history of all the builds done for a release [1] 2. recently we found a bug that caused OST to fail due to out of memory because it tried to sync the entire tested repo into memory ( that's how OST works ), so the tested repo was removed from check-patch. 3. This means that now check-patch is only using the repos in the reposync file, which for 4.1 is latest released. 4. vdsm-jsonrpc-java 1.3.9 wasn't released in any official oVirt 4.1 release, this is why the job used 1.3.8 which is the latest released. 5. We also don't want to replace the default repos for OST on 4.1 to something other than released, because the basic suite per release should always check against official release [2] 6. As a side note - manual jobs also support running on latest tested, so this issue is solely restricted to 'check-patch' jobs. We do however believe that running check-patch on latest code is important, so we'll look into providing an alternate solution that won't break any of the above restrictions, Suggestions are welcome of course. [1] It is done so anyone that wants to check oVirt can do it w/o worrying that a pkg will be removed during testing ( something that was happening when used experimental lastest.tested repo ) [2] As opposed to experimental flows which DO check against latest code, which is why 4.1 experimental didn't fail on this issue, as it used 1.3.9
On Sun, Mar 19, 2017 at 10:27 AM, Barak Korren <bkorren@redhat.com> wrote:
בתאריך 17 במרץ 2017 02:32 PM, "Piotr Kliczewski" < piotr.kliczewski@gmail.com> כתב:
The change was merged 2 weeks ago. How can we make sure not to waste people time next time to analyze the issue?
"Merged" is hardly "released".
As long as a fix does not make it to a release, users can still come across the issue, and so can OST. I can't think of a quick way to avoid that, but I'm open to suggestions....
WRT getting more frequent oVirt releases, I'm hardly in a position to give input about that.
_______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
_______________________________________________ Devel mailing list Devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/devel
-- Eyal Edri Associate Manager RHV DevOps EMEA ENG Virtualization R&D Red Hat Israel
phone: +972-9-7692018 <+972%209-769-2018> irc: eedri (on #tlv #rhev-dev #rhev-integ)
-- Eyal Edri Associate Manager RHV DevOps EMEA ENG Virtualization R&D Red Hat Israel phone: +972-9-7692018 irc: eedri (on #tlv #rhev-dev #rhev-integ)
participants (7)
-
Barak Korren -
Eyal Edri -
Oved Ourfali -
Pavel Zhukov -
Piotr Kliczewski -
Piotr Kliczewski -
Yaniv Kaul