Assay run imports are successful, but no data rows are visible

General Server Forum (Inactive)
Assay run imports are successful, but no data rows are visible jmb  2018-06-06 12:57
Status: Closed
 

I have an assay defined with multiple batches/runs uploaded that were previously uploaded successfully and a trigger script to populate additional columns. Recently I tried to re-import one of my runs after making some edits to my trigger script. The re-import was successful in that no errors are thrown and the new run shows up in my Assay Runs webpart, but when I clicked on the newly created run name (or the View Results button) to view the assay results I didn't see any associated data rows.

To troubleshoot, I decided to delete my existing batches/runs/data and import them from scratch to see if this would resolve the issue. But I am seeing the same issue now when importing 'new' data: the run itself imports and is visible in the webpart, clicking on the run returns no rows associated with the new Run integer id. And if I remove the 'Run=[###]' filter while viewing assay results I still see an empty grid displaying 'No data to show'.

So far I've verified that this same behavior occurs even after I disable my trigger script. I've also verified that new records are being inserted into the underlying postgres tables (exp.experimentrun, exp.data, and assayresult.c5d91_nanodrop_qc_data_fields) after import, as shown in the query below:
Before importing a new run:

labkey=# SELECT rowid FROM exp.experimentrun;
 rowid 
-------
     1
     2
(2 rows)

labkey=# SELECT DISTINCT dataid FROM assayresult.c5d91_nanodrop_qc_data_fields;
 dataid 
--------
(0 rows)

The same two queries after import:

labkey=# SELECT rowid FROM exp.experimentrun;
 rowid 
-------
     1
     2
   136
(3 rows)

labkey=# SELECT rowid,dataid FROM assayresult.c5d91_nanodrop_qc_data_fields;

  3750 |    269
  3751 |    269
  3752 |    269
  3753 |    269
  3754 |    269
  3755 |    269
  3756 |    269
  3757 |    269
  3758 |    269
  3759 |    269
  3760 |    269
  3761 |    269
  3762 |    269
  3763 |    269
  3764 |    269
  3765 |    269
  3766 |    269
  3767 |    269
  3768 |    269
  3769 |    269
  3770 |    269
  3771 |    269
  3772 |    269
  3773 |    269
  3774 |    269
  3775 |    269
  3776 |    269
(39 rows)

Any ideas on how to fix this would be much appreciated. Thanks.

 
 
jmb responded:  2018-06-06 16:10

A quick additional note on this: I restarted the server and attempted to re-import one of the assays again. Although I don't see any errors in labkey.log when I try to re-import @ timestamp 18:45 (no errors in labkey-error.log either), I do get a warning @ 18:40:09 during the server reboot that pertains to one of my assay files. May not be relevant to the problem since my issue applies to any file I try to import/reimport in this assay, but just in case the lines I'm referencing are below:

WARN  FileQueryUpdateService   2018-06-06 18:40:09,121      SearchService:index : More than one row returned for data file: WHERE ((DataFileUrl = '/usr/local/labkey/files/NDDdb/assaydata/Nucleic%20Acid%202018%20%2004%20%2027.csv') OR (DataFileUrl = 'file:/usr/local/labkey/files/NDDdb/assaydata/Nucleic%20Acid%202018%20%2004%20%2027.csv') OR (DataFileUrl = 'file:///usr/local/labkey/files/NDDdb/assaydata/Nucleic%20Acid%202018%20%2004%20%2027.csv')) AND (Folder = '73108fce-1b3e-1036-9b0c-e9a3d9d29600')
INFO  ExperimentServiceImpl    2018-06-06 18:45:02,963 ps-jsse-nio-8443-exec-10 : Rebuilding edges for runId 139
INFO  ExperimentServiceImpl    2018-06-06 18:45:02,972 ps-jsse-nio-8443-exec-10 : Removing edges for run 139
INFO  ExperimentServiceImpl    2018-06-06 18:45:03,053 ps-jsse-nio-8443-exec-10 :   edge counts: input data=0, input materials=0, output data=1, output materials=0, total=0
INFO  ExperimentServiceImpl    2018-06-06 18:45:03,053 ps-jsse-nio-8443-exec-10 :   synced edges in 0.090s
INFO  ExperimentServiceImpl    2018-06-06 18:45:19,074 ps-jsse-nio-8443-exec-10 : Rebuilding edges for runId 139
INFO  ExperimentServiceImpl    2018-06-06 18:45:19,081 ps-jsse-nio-8443-exec-10 : Removing edges for run 139
INFO  ExperimentServiceImpl    2018-06-06 18:45:19,082 ps-jsse-nio-8443-exec-10 :   edge counts: input data=0, input materials=1, output data=2, output materials=0, total=2
INFO  ExperimentServiceImpl    2018-06-06 18:45:19,095 ps-jsse-nio-8443-exec-10 :   synced edges in 0.020s
 
jmb responded:  2018-06-08 12:32

One more update: Digging through my postgres logs, I've found the query for the assay results that's coming up empty handed:

2018-06-08 11:30:33.191 EDT,"postgres","labkey",18028,"127.0.0.1:43154",5b1aa0b4.466c,156090,"SELECT",2018-06-08 11:28:52 EDT,3/98329,0,LOG,00000,"execute <unnamed>/C_28880: SELECT *
FROM (
SELECT 
Data.""plate id"" AS Plate_ID,
Data.""sample id"" AS Sample_ID,
Data.a260 AS A260,
Data.a280 AS A280,
Data.well AS Well,
Data.nreads AS nReads,
Data.avgdna AS AvgDNA,
Data.stddna AS StdDNA,
Data.meddna AS MedDNA,
Data.""260/280"" AS _260_fs_280,
Data.avg260280 AS Avg260280,
Data.std260280 AS Std260280,
Data.med260280 AS Med260280,
Data.""260/230"" AS _260_fs_230,
Data.avg260230 AS Avg260230,
Data.std260230 AS Std260230,
Data.med260230 AS Med260230,
Data.date AS Date,
Data.time AS Time,
Data.""conc."" AS Conc_,
Data.units AS Units,
Data.""na type"" AS NA_Type,
CAST((SELECT StringValue FROM exp.ObjectProperty WHERE exp.ObjectProperty.PropertyId = 419 AND exp.ObjectProperty.ObjectId = Data$Run$LSID$_C.ObjectId) AS VARCHAR(4000)) AS Run_fs_Technician,
(SELECT Container FROM exp.Data d WHERE d.RowId = Data.DataId) AS Folder,
Data.rowid AS RowId,
Data$Run$.rowid AS Run_fs_RowId,
CASE WHEN Data$Run$.ReplacedByRunId IS NULL THEN $1 ELSE $2 END AS Run_fs_Replaced
FROM (SELECT innerResults.*, innerData.RunId AS Run FROM
(SELECT * FROM assayresult.c5d140_nanodrop_data_fields
WHERE ((SELECT d.Container FROM exp.Data d WHERE d.RowId = DataId)='73108fce-1b3e-1036-9b0c-e9a3d9d29600'/* NDDdb */)) innerResults
INNER JOIN exp.data innerData ON (innerData.RowId = innerResults.DataId)) Data 

	LEFT OUTER JOIN (SELECT * FROM exp.experimentrun
WHERE ((protocollsid = $3)) AND (Container='73108fce-1b3e-1036-9b0c-e9a3d9d29600'/* NDDdb */)) Data$Run$ ON (Data.Run = Data$Run$.rowid)

	LEFT OUTER JOIN exp.object Data$Run$LSID$_C ON (Data$Run$.lsid = Data$Run$LSID$_C.objecturi)) x
WHERE (Run_fs_RowId = $4) AND (Run_fs_Replaced = $5) AND (Run_fs_RowId = $6)
ORDER BY RowId ASC
LIMIT 101","parameters: $1 = 'f', $2 = 't', $3 = 'urn:lsid:labkey.com:GeneralAssayProtocol.Folder-5:NanoDrop', $4 = '80', $5 = 'f', $6 = '182'",,,,,,,,"PostgreSQL JDBC Driver"

If I'm reading the query correctly, the line

WHERE (Run_fs_RowId = $4) AND (Run_fs_Replaced = $5) AND (Run_fs_RowId = $6)

appears to be the culprit. The correct runID here is 182, but I have no idea where the other runID, 80, is coming from (there are no rows in exp.experimentrun with rowid=80). I had a previous assay on my server that was also named 'NanoDrop' and was later deleted, and I'm guessing the assay's lsid still being associated with an orphaned run in another table that was loaded previously. I've verified that creating a new assay with the same design and a new name allows me to load and reload data without encountering the issue from my first post. Unfortunately, just using a new name for the assay isn't an option here, and it would be useful to know how this error comes about in the first place, so I'm still looking for a fix.

 
jmb responded:  2018-06-11 16:49

Still another update while trying to find a repro for this: this issue doesn't appear to be limited to assays that have been deleted then later recreated under the same name. Last week I made a new assay aptly named 'NanoDropExactCopy06082018' and successfully imported some runs into it ('successfully' meaning I could click on a run name in an 'Assay Runs' webpart and view the results). From my postgres logs, here's the query that executed on the server when I clicked on my run (runID = 183) to view my results last week when it still worked:

2018-06-08 13:13:45.284 EDT,"postgres","labkey",18037,"127.0.0.1:43158",5b1aa0be.4675,125824,"SELECT",2018-06-08 11:29:02 EDT,4/76019,0,LOG,00000,"execute <unnamed>/C_27317: SELECT *
FROM (
SELECT 
Data.""plate id"" AS Plate_ID,
Data.well AS Well,
Data.""sample id"" AS Sample_ID,
Data.""user id"" AS User_ID,
Data.date AS Date,
Data.time AS Time,
Data.""conc."" AS Conc_,
Data.units AS Units,
Data.a260 AS A260,
Data.a280 AS A280,
Data.""260/280"" AS _260_fs_280,
Data.""260/230"" AS _260_fs_230,
Data.""na type"" AS NA_Type,
Data.nreads AS nReads,
Data.avgdna AS AvgDNA,
Data.avg260280 AS Avg260280,
Data.avg260230 AS Avg260230,
Data.stddna AS StdDNA,
Data.std260280 AS Std260280,
Data.std260230 AS Std260230,
Data.meddna AS MedDNA,
Data.med260280 AS Med260280,
Data.med260230 AS Med260230,
CAST((SELECT StringValue FROM exp.ObjectProperty WHERE exp.ObjectProperty.PropertyId = 3876 AND exp.ObjectProperty.ObjectId = Data$Run$LSID$_C.ObjectId) AS VARCHAR(4000)) AS Run_fs_Technician,
(SELECT DateTimeValue FROM exp.ObjectProperty WHERE exp.ObjectProperty.PropertyId = 3877 AND exp.ObjectProperty.ObjectId = Data$Run$LSID$_C.ObjectId) AS Run_fs_Date_run,
CAST((SELECT StringValue FROM exp.ObjectProperty WHERE exp.ObjectProperty.PropertyId = 3878 AND exp.ObjectProperty.ObjectId = Data$Run$LSID$_C.ObjectId) AS VARCHAR(4000)) AS Run_fs_Notes,
(SELECT Container FROM exp.Data d WHERE d.RowId = Data.DataId) AS Folder,
Data.rowid AS RowId,
Data$Run$.rowid AS Run_fs_RowId,
CASE WHEN Data$Run$.ReplacedByRunId IS NULL THEN $1 ELSE $2 END AS Run_fs_Replaced
FROM (SELECT innerResults.*, innerData.RunId AS Run FROM
(SELECT * FROM assayresult.c5d143_nanodropexactcopy06082018_data_fields
WHERE ((SELECT d.Container FROM exp.Data d WHERE d.RowId = DataId)='73108fce-1b3e-1036-9b0c-e9a3d9d29600'/* NDDdb */)) innerResults
INNER JOIN exp.data innerData ON (innerData.RowId = innerResults.DataId)) Data 

	LEFT OUTER JOIN (SELECT * FROM exp.experimentrun
WHERE ((protocollsid = $3)) AND (Container='73108fce-1b3e-1036-9b0c-e9a3d9d29600'/* NDDdb */)) Data$Run$ ON (Data.Run = Data$Run$.rowid)

	LEFT OUTER JOIN exp.object Data$Run$LSID$_C ON (Data$Run$.lsid = Data$Run$LSID$_C.objecturi)) x
WHERE (Run_fs_Replaced = $4) AND (Run_fs_RowId = $5)
ORDER BY RowId ASC
LIMIT 101","parameters: $1 = 'f', $2 = 't', $3 = 'urn:lsid:labkey.com:GeneralAssayProtocol.Folder-5:NanoDropExactCopy06082018', $4 = 'f', $5 = '183'",,,,,,,,"PostgreSQL JDBC Driver"

And here's the query that executes when I try to view the results of the same run today. No rows are returned this time. The query is identical until you get to the JOIN conditions specified in the very last code block--the same lines I highlighted in my last post:

2018-06-11 18:29:36.121 EDT,"postgres","labkey",26668,"127.0.0.1:44636",5b1ef7a0.682c,82,"SELECT",2018-06-11 18:28:48 EDT,2/57,0,LOG,00000,"execute <unnamed>/C_19: SELECT *
FROM (
SELECT 
Data.""plate id"" AS Plate_ID,
Data.well AS Well,
Data.""sample id"" AS Sample_ID,
Data.""user id"" AS User_ID,
Data.date AS Date,
Data.time AS Time,
Data.""conc."" AS Conc_,
Data.units AS Units,
Data.a260 AS A260,
Data.a280 AS A280,
Data.""260/280"" AS _260_fs_280,
Data.""260/230"" AS _260_fs_230,
Data.""na type"" AS NA_Type,
Data.nreads AS nReads,
Data.avgdna AS AvgDNA,
Data.avg260280 AS Avg260280,
Data.avg260230 AS Avg260230,
Data.stddna AS StdDNA,
Data.std260280 AS Std260280,
Data.std260230 AS Std260230,
Data.meddna AS MedDNA,
Data.med260280 AS Med260280,
Data.med260230 AS Med260230,
CAST((SELECT StringValue FROM exp.ObjectProperty WHERE exp.ObjectProperty.PropertyId = 3876 AND exp.ObjectProperty.ObjectId = Data$Run$LSID$_C.ObjectId) AS VARCHAR(4000)) AS Run_fs_Technician,
(SELECT DateTimeValue FROM exp.ObjectProperty WHERE exp.ObjectProperty.PropertyId = 3877 AND exp.ObjectProperty.ObjectId = Data$Run$LSID$_C.ObjectId) AS Run_fs_Date_run,
CAST((SELECT StringValue FROM exp.ObjectProperty WHERE exp.ObjectProperty.PropertyId = 3878 AND exp.ObjectProperty.ObjectId = Data$Run$LSID$_C.ObjectId) AS VARCHAR(4000)) AS Run_fs_Notes,
(SELECT Container FROM exp.Data d WHERE d.RowId = Data.DataId) AS Folder,
Data.rowid AS RowId,
Data$Run$.rowid AS Run_fs_RowId,
CASE WHEN Data$Run$.ReplacedByRunId IS NULL THEN $1 ELSE $2 END AS Run_fs_Replaced
FROM (SELECT innerResults.*, innerData.RunId AS Run FROM
(SELECT * FROM assayresult.c5d143_nanodropexactcopy06082018_data_fields
WHERE ((SELECT d.Container FROM exp.Data d WHERE d.RowId = DataId)='73108fce-1b3e-1036-9b0c-e9a3d9d29600'/* NDDdb */)) innerResults
INNER JOIN exp.data innerData ON (innerData.RowId = innerResults.DataId)) Data 

	LEFT OUTER JOIN (SELECT * FROM exp.experimentrun
WHERE ((protocollsid = $3)) AND (Container='73108fce-1b3e-1036-9b0c-e9a3d9d29600'/* NDDdb */)) Data$Run$ ON (Data.Run = Data$Run$.rowid)

	LEFT OUTER JOIN exp.object Data$Run$LSID$_C ON (Data$Run$.lsid = Data$Run$LSID$_C.objecturi)) x
WHERE (Run_fs_RowId = $4) AND (Run_fs_Replaced = $5) AND (Run_fs_RowId = $6)
ORDER BY RowId ASC
LIMIT 101","parameters: $1 = 'f', $2 = 't', $3 = 'urn:lsid:labkey.com:GeneralAssayProtocol.Folder-5:NanoDropExactCopy06082018', $4 = '190', $5 = 'f', $6 = '183'",,,,,,,,"PostgreSQL JDBC Driver"

Still trying to find a repro, but I've attached my LabKey log documenting the server activity that's occurred between 6/8 and today.

 
Jon (LabKey DevOps) responded:  2018-06-22 20:56
Hi Judson,

Thanks for the detailed information.

Since that runID of 80 is coming up as a parameter value, that would imply that there is a URL filter with that value.

Can you provide us with URL you're using that corresponds with that query?

Regards,

Jon