mbari-org / vars-annotation

Video Annotation Application for MBARI's Media Management (M3) software stack
https://docs.mbari.org/vars-annotation/
Apache License 2.0
16 stars 6 forks source link

D1017 not merging; need data today #89

Closed lindakuhnz closed 6 years ago

lindakuhnz commented 6 years ago

Can't get this dive to merge, and need data today. Please help!

lindakuhnz commented 6 years ago

Had already checked; no issues with the dive being entered correctly or CTD data not being available.

lindakuhnz commented 6 years ago

root@eb85254dc31b:/opt/m3-merge-rov/bin# ./merge_expd 'Doc Ricketts' 1017 2018-08-20 22:57:01 [main] DEBUG org.mbari.expd.jdbc.DiveDAOImpl - Executing SQL query: SELECT d.diveid AS DiveID, d.rovname AS RovName, d.divenumber AS DiveNumber, d.divestartdtg AS DiveStartDtg, d.diveenddtg AS DiveEndDtg, d.divechiefscientist AS DiveChiefScientist, d.BriefAccomplishments, ds.avgrovlat AS Latitude, ds.avgrovlon AS Longitude FROM DiveSummary ds RIGHT OUTER JOIN Dive d ON d.DiveID = ds.diveid WHERE d.rovname = 'docr' AND d.divenumber = 1017 2018-08-20 22:57:01 [main] DEBUG org.mbari.expd.jdbc.DiveDAOImpl - Opening JDBC connection:everyone @ jdbc:jtds:sqlserver://solstice.shore.mbari.org:1433/EXPD Exception in thread "main" org.mbari.sql.DBException: Failed to execute the following SQL on jdbc:jtds:sqlserver://solstice.shore.mbari.org:1433/EXPD: SELECT d.diveid AS DiveID, d.rovname AS RovName, d.divenumber AS DiveNumber, d.divestartdtg AS DiveStartDtg, d.diveenddtg AS DiveEndDtg, d.divechiefscientist AS DiveChiefScientist, d.BriefAccomplishments, ds.avgrovlat AS Latitude, ds.avgrovlon AS Longitude FROM DiveSummary ds RIGHT OUTER JOIN Dive d ON d.DiveID = ds.diveid WHERE d.rovname = 'docr' AND d.divenumber = 1017 at org.mbari.sql.QueryableImpl.executeQueryFunction(QueryableImpl.java:89) at org.mbari.expd.jdbc.DiveDAOImpl.findByPlatformAndDiveNumber(DiveDAOImpl.java:83) at org.mbari.m3.merge.platforms.rov.SingleMergeApp$.main(SingleMergeApp.scala:37) at org.mbari.m3.merge.platforms.rov.SingleMergeApp.main(SingleMergeApp.scala) Caused by: java.sql.SQLException: Network error IOException: Connection refused (Connection refused) at net.sourceforge.jtds.jdbc.JtdsConnection.(JtdsConnection.java:436) at net.sourceforge.jtds.jdbc.Driver.connect(Driver.java:184) at java.sql.DriverManager.getConnection(DriverManager.java:664) at java.sql.DriverManager.getConnection(DriverManager.java:247) at org.mbari.sql.QueryableImpl.getConnection(QueryableImpl.java:133) at org.mbari.sql.QueryableImpl.executeQueryFunction(QueryableImpl.java:69) ... 3 more Caused by: java.net.ConnectException: Connection refused (Connection refused) at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:589) at net.sourceforge.jtds.jdbc.SharedSocket.createSocketForJDBC3(SharedSocket.java:288) at net.sourceforge.jtds.jdbc.SharedSocket.(SharedSocket.java:251) at net.sourceforge.jtds.jdbc.JtdsConnection.(JtdsConnection.java:331) ... 8 more root@eb85254dc31b:/opt/m3-merge-rov/bin#

hohonuuli commented 6 years ago

OH. The database was moved from solstice to perseus last week. I forgot to update this code. I'm on it.

hohonuuli commented 6 years ago

Merged

hohonuuli commented 6 years ago

To get new merge code, run docker pull portal.shore.mbari.org:5000/portal/m3-merge-rov

lindakuhnz commented 6 years ago

D1015 not merging; ran this, VARS query shows unmarked data (before and after). Tried 3 times on two different computers.

Last login: Wed Aug 22 07:09:01 on ttys000 bathysphere:~ linda$ docker pull portal.shore.mbari.org:5000/portal/m3-merge-rov Using default tag: latest latest: Pulling from portal/m3-merge-rov Digest: sha256:50795c7ffbe4eb0da25f25203834768ab746c5ae4d7d14f5d9c97470f8194f0b Status: Image is up to date for portal.shore.mbari.org:5000/portal/m3-merge-rov:latest bathysphere:~ linda$ docker run -it portal.shore.mbari.org:5000/portal/m3-merge-rov /bin/bash root@68113e4ed188:/# cd /opt/m3-merge-rov/bin root@68113e4ed188:/opt/m3-merge-rov/bin# ./merge_expd 'Doc Ricketts' 1015 14:11:43,991 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 14:11:43,991 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 14:11:43,992 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/opt/m3-merge-rov/conf/logback.xml] 14:11:43,992 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs multiple times on the classpath. 14:11:43,993 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [jar:file:/opt/m3-merge-rov/lib/m3-merge-rov_2.12-1.0-SNAPSHOT.jar!/logback.xml] 14:11:43,993 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [file:/opt/m3-merge-rov/conf/logback.xml] 14:11:44,083 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set 14:11:44,084 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 14:11:44,093 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE] 14:11:44,161 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.fusesource.scalate] to WARN 14:11:44,161 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [httpclient.wire.header] to WARN 14:11:44,161 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.mbari.m3.corelib.services.annosaurus.v1.AnnoWebServiceFactory] to WARN 14:11:44,161 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.mbari.m3.corelib.services.vampiresquid.v1.VamWebServiceFactory] to WARN 14:11:44,161 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [ org.mbari.expd.jdbc] to WARN 14:11:44,161 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG 14:11:44,161 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT] 14:11:44,162 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 14:11:44,162 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@47fd17e3 - Registering current configuration as safe fallback point

2018-08-22 14:11:44 [main] DEBUG org.mbari.m3.merge.platforms.rov.LocalSingleMergeApp$ - Starting merge for Doc Ricketts #1015 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - HikariPool-1 - configuration: 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - allowPoolSuspension.............false 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - autoCommit......................true 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - catalog.........................none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionInitSql...............none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionTestQuery............."SELECT 1" 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionTimeout...............30000 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSource......................none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceClassName.............none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceJNDI..................none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceProperties............{password=} 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - driverClassName.................none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - healthCheckProperties...........{} 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - healthCheckRegistry.............none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - idleTimeout.....................600000 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - initializationFailTimeout.......1 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - isolateInternalQueries..........false 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - jdbcUrl.........................jdbc:jtds:sqlserver://fog.shore.mbari.org:1433/M3_ANNOTATIONS 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - leakDetectionThreshold..........0 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - maxLifetime.....................1800000 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - maximumPoolSize.................10 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - metricRegistry..................none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - metricsTrackerFactory...........none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - minimumIdle.....................10 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - password........................ 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - poolName........................"HikariPool-1" 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - readOnly........................false 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - registerMbeans..................false 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - scheduledExecutor...............none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - schema..........................none 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - threadFactory...................internal 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - transactionIsolation............default 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - username........................"m3dbuser" 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.HikariConfig - validationTimeout...............5000 2018-08-22 14:11:45 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting... 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.util.DriverDataSource - Loaded driver with class name net.sourceforge.jtds.jdbc.Driver for jdbcUrl=jdbc:jtds:sqlserver://fog.shore.mbari.org:1433/M3_ANNOTATIONS 2018-08-22 14:11:45 [main] INFO com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Driver does not support get/set network timeout for connections. (null) 2018-08-22 14:11:45 [main] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@74ea2410 2018-08-22 14:11:45 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed. 2018-08-22 14:11:45 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0) 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@2ea2a80f 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@206543ab 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@245ac37f 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@61584990 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@5a017764 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@50730f94 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@22c06fde 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@177b6df 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection net.sourceforge.jtds.jdbc.JtdsConnection@501c4bc2 2018-08-22 14:11:45 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - After adding stats (total=10, active=0, idle=10, waiting=0) 2018-08-22 14:11:45 [main] DEBUG org.mbari.expd.jdbc.DiveDAOImpl - Executing SQL query: SELECT d.diveid AS DiveID, d.rovname AS RovName, d.divenumber AS DiveNumber, d.divestartdtg AS DiveStartDtg, d.diveenddtg AS DiveEndDtg, d.divechiefscientist AS DiveChiefScientist, d.BriefAccomplishments, ds.avgrovlat AS Latitude, ds.avgrovlon AS Longitude FROM DiveSummary ds RIGHT OUTER JOIN Dive d ON d.DiveID = ds.diveid WHERE d.rovname = 'docr' AND d.divenumber = 1015 2018-08-22 14:11:45 [main] DEBUG org.mbari.expd.jdbc.DiveDAOImpl - Opening JDBC connection:everyone @ jdbc:jtds:sqlserver://perseus.shore.mbari.org:1433/EXPD 2018-08-22 14:11:45 [scala-execution-context-global-16] DEBUG org.mbari.expd.jdbc.DiveDAOImpl - Executing SQL query: SELECT d.diveid AS DiveID, d.rovname AS RovName, d.divenumber AS DiveNumber, d.divestartdtg AS DiveStartDtg, d.diveenddtg AS DiveEndDtg, d.divechiefscientist AS DiveChiefScientist, d.BriefAccomplishments, ds.avgrovlat AS Latitude, ds.avgrovlon AS Longitude FROM DiveSummary ds RIGHT OUTER JOIN Dive d ON d.DiveID = ds.diveid WHERE d.rovname = 'docr' AND d.divestartdtg < '2018-04-20 13:27:55' AND d.diveenddtg > '2018-04-20 13:27:55' 2018-08-22 14:11:45 [scala-execution-context-global-16] DEBUG org.mbari.expd.jdbc.DiveDAOImpl - Opening JDBC connection:everyone @ jdbc:jtds:sqlserver://perseus.shore.mbari.org:1433/EXPD 2018-08-22 14:11:45 [scala-execution-context-global-16] WARN org.mbari.m3.merge.platforms.rov.EXPD$ - An empty EXPD data collection was found. Unable to convert to AncillaryData 2018-08-22 14:11:45 [main] INFO org.mbari.m3.merge.platforms.rov.LocalSingleMergeApp$ - COMPLETED MERGE! Merged 67 videos in dive Doc Ricketts #1015 root@68113e4ed188:/opt/m3-merge-rov/bin#

hohonuuli commented 6 years ago

The start and end dates are set to the same value in expd database for that dive. Someone needs to edit it and set the correct values.

lindakuhnz commented 6 years ago

I’d checked for that already as a potential problem. Start and end time match CTD. untitled See attached.

lonnylundsten commented 6 years ago

This shows a dive duration of 138 hours. Its probably not correct, note that the orange bar doesn’t match pilots log or ctd in length.

Lonny Lundsten Senior Research Technician Monterey Bay Aquarium Research Institute

7700 Sandholdt Road Moss Landing, CA 95039 Phone: (831) 775-1762 lonny@mbari.org

On Aug 22, 2018, at 7:38 AM, lindakuhnz notifications@github.com wrote:

I’d checked for that already as a potential problem. Start and end time match CTD. https://user-images.githubusercontent.com/38045059/44470359-50b28680-a5de-11e8-84e0-a714b665b265.png See attached.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/mbari-media-management/vars-annotation/issues/89#issuecomment-415055340, or mute the thread https://github.com/notifications/unsubscribe-auth/AfBPNJ_vZ01VDLa093u6UDwssak0CqAiks5uTWzWgaJpZM4WEJ9Z.

lindakuhnz commented 6 years ago

The 138 hour bar is only because I opened the dive to check for the times (without altering anything). CTD and dive time are correct at 7.695 hours (see what they are currently set to)

hohonuuli commented 6 years ago

Runing the following to verify the start times:

SELECT 
  d.diveid AS DiveID, 
  d.rovname AS RovName,
  d.divenumber AS DiveNumber, 
  d.divestartdtg AS DiveStartDtg, 
  d.diveenddtg AS DiveEndDtg, 
  d.divechiefscientist AS DiveChiefScientist, 
  d.BriefAccomplishments, 
  ds.avgrovlat AS Latitude, 
  ds.avgrovlon AS Longitude 
FROM 
  DiveSummary ds RIGHT OUTER JOIN 
  Dive d ON d.DiveID = ds.diveid WHERE d.rovname = 'docr' AND d.divenumber = 1015

It's returning 4/20/2018 1:44:15 PM and 4/20/2018 9:26:00 PM which are now different since you first ran the merge. Someone has updated the start and end time values in the database. You can rerun the merge and it should pick up the new values

lonnylundsten commented 6 years ago

Still not merging and still retrieving bad times: SELECT d.diveid AS DiveID, d.rovname AS RovName, d.divenumber AS DiveNumber, d.divestartdtg AS DiveStartDtg, d.diveenddtg AS DiveEndDtg, d.divechiefscientist AS DiveChiefScientist, d.BriefAccomplishments, ds.avgrovlat AS Latitude, ds.avgrovlon AS Longitude FROM DiveSummary ds RIGHT OUTER JOIN Dive d ON d.DiveID = ds.diveid WHERE d.rovname = 'docr' AND d.divestartdtg < '2018-04-20 13:27:55' AND d.diveenddtg > '2018-04-20 13:27:55’

Lonny Lundsten Senior Research Technician Monterey Bay Aquarium Research Institute

7700 Sandholdt Road Moss Landing, CA 95039 Phone: (831) 775-1762 lonny@mbari.org

On Aug 22, 2018, at 9:37 AM, Brian Schlining notifications@github.com wrote:

Runing the following to verify the start times:

SELECT

d.diveid AS DiveID,

d.rovname AS RovName,

d.divenumber AS DiveNumber,

d.divestartdtg AS DiveStartDtg,

d.diveenddtg AS DiveEndDtg,

d.divechiefscientist AS DiveChiefScientist,

d.BriefAccomplishments ,

ds.avgrovlat AS Latitude,

ds.avgrovlon AS Longitude

FROM

DiveSummary ds RIGHT OUTER JOIN

Dive d ON d.DiveID = ds.diveid WHERE d.rovname = 'docr' AND d.divenumber = 1015 It's returning 4/20/2018 1:44:15 PM and 4/20/2018 9:26:00 PM which are now different since you first ran the merge. Someone has updated the start and end time values in the database. You can rerun the merge and it should pick up the new values

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

lonnylundsten commented 6 years ago

Looks like this is running the merge against fog not perseus see bold text below:

root@0bb69e7617ef:/opt/m3-merge-rov/bin# ./merge_expd 'Doc Ricketts' 1015 [...] 2018-08-22 16:48:12 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting... 2018-08-22 16:48:12 [main] DEBUG com.zaxxer.hikari.util.DriverDataSource - Loaded driver with class name net.sourceforge.jtds.jdbc.Driver for jdbcUrl=jdbc:jtds:sqlserver://fog.shore.mbari.org:1433/M3_ANNOTATIONS 2018-08-22 16:48:12 [main] INFO com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Driver does not support get/set network timeout for connections. (null) [...] 2018-08-22 16:48:13 [main] INFO org.mbari.m3.merge.platforms.rov.LocalSingleMergeApp$ - COMPLETED MERGE! Merged 67 videos in dive Doc Ricketts #1015

hohonuuli commented 6 years ago

Build script is too smart. Fixed now.