org.h2.jdbc.JdbcSQLSyntaxErrorException: Column "MODIFIED" not found

[petermag]

In looking for clues for a problem I notice this

ERROR 2021-03-06 17:24:22.365 [HTTPv2 Request Worker 30] null
org.h2.jdbc.JdbcSQLSyntaxErrorException: Column "MODIFIED" not found [42122-199]


Looks like a database has not been setup correctly

Regards
Peter

[mik_s]

Possibly something wrong with the database. will need trace logs to find the cause of the error though. See the red section above.

[petermag]

Hi
As requested
Debug.log too big even compressed, so I edited it, 26MB (7z)
Regards
Peter

[mik_s]

Will probably need the full log as everything before the first database error is missing. Looking at the first log you posted there are a few more errors before that that could be the cause. can you try posting the first half?

I think the reason that your log is so large is that UMS is scanning all your media and creating thumbnails, all that is getting logged so might be better to wait till that is finished then restarting UMS to make new logs.

I don't know much about the database but at a guess it is missing the column "MODIFIED" in some table. I can see tables being created in your first log but not much else.

This is something the devs will have to look into I think.

[petermag]

Hi

I used 7zips volume feature, here are the bits for the full log, you will have to rename debug.7z.001.7z to debug.7z.001 etc.

first three

Regards
PeterM

[petermag]

Hi

next three

Regards
PeterM

[mik_s]

Wow that is a large log file, nearly 1GB. No wonder you had difficulty posting.

It appears that the errors occur after browsing certain directorys with dates like "2020 09 27"

Code: Select all

TRACE 2021-03-08 19:17:57.446 [HTTPv2 Request Worker 28] net.pms.configuration.RendererConfiguration Matched media renderer "[LG] webOS TV UN7300PTC" based on address 192.168.10.105
DEBUG 2021-03-08 19:17:57.446 [HTTPv2 Request Worker 28] net.pms.network.RequestHandlerV2 Recognized media renderer "[LG] webOS TV UN7300PTC"
TRACE 2021-03-08 19:17:57.447 [HTTPv2 Request Worker 28] net.pms.network.RequestHandlerV2 Received a browse request from [LG] webOS TV UN7300PTC [LG WebOS TV] (192.168.10.105:49636):

POST /upnp/control/content_directory HTTP/1.1

HEADER:
  SOAPAction: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
  DLNADeviceName.lge.com: %5bLG%5d%20webOS%20TV%20UN7300PTC
  User-Agent: Linux/4.4.84-612.21.6.jardine.2 UPnP/1.0 LGE WebOS TV LGE_DLNA_SDK/1.6.0/03.21.36 DLNADOC/1.50
  Host: 192.168.10.103:5001
  Content-Length: 679
  Content-Type: text/xml; charset="utf-8"

CONTENT:
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
  <s:Body>
    <u:Browse xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1">
      <ObjectID>49377</ObjectID>
      <BrowseFlag>BrowseDirectChildren</BrowseFlag>
      <Filter>res@resolution,res@nrAudioChannels,res@sampleFrequency,res@bitrate,dc:creator,res@dlna:cleartextSize,dc:date,upnp:genre,res,res@duration,res@size,upnp:albumArtURI,upnp:originalTrackNumber,upnp:album,upnp:artist,upnp:author</Filter>
      <StartingIndex>0</StartingIndex>
      <RequestedCount>30</RequestedCount>
      <SortCriteria/>
    </u:Browse>
  </s:Body>
</s:Envelope>

ERROR 2021-03-08 19:17:57.456 [HTTPv2 Request Worker 28] net.pms.dlna.DLNAMediaDatabase null
org.h2.jdbc.JdbcSQLSyntaxErrorException: Column "MODIFIED" not found [42122-199]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:451)
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:427)
	at org.h2.message.DbException.get(DbException.java:205)
	at org.h2.message.DbException.get(DbException.java:181)
	at org.h2.jdbc.JdbcResultSet.getColumnIndex(JdbcResultSet.java:3214)
	at org.h2.jdbc.JdbcResultSet.get(JdbcResultSet.java:3287)
	at org.h2.jdbc.JdbcResultSet.getTimestamp(JdbcResultSet.java:494)
	at net.pms.dlna.DLNAMediaDatabase.getFiles(DLNAMediaDatabase.java:1584)
	at net.pms.dlna.virtual.MediaLibraryFolder.doRefreshChildren(MediaLibraryFolder.java:257)
	at net.pms.dlna.virtual.MediaLibraryFolder.discoverChildren(MediaLibraryFolder.java:107)
	at net.pms.dlna.DLNAResource.discoverChildren(DLNAResource.java:1290)
	at net.pms.dlna.DLNAResource.discoverWithRenderer(DLNAResource.java:1153)
	at net.pms.dlna.DLNAResource.getDLNAResources(DLNAResource.java:1075)
	at net.pms.network.RequestV2.browseSearchHandler(RequestV2.java:1147)
	at net.pms.network.RequestV2.browseHandler(RequestV2.java:1077)
	at net.pms.network.RequestV2.answer(RequestV2.java:659)
	at net.pms.network.RequestHandlerV2.writeResponse(RequestHandlerV2.java:404)
	at net.pms.network.RequestHandlerV2.messageReceived(RequestHandlerV2.java:260)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
	at org.jboss.netty.handler.stream.ChunkedWriteHandler.handleUpstream(ChunkedWriteHandler.java:142)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
	at org.jboss.netty.handler.codec.http.HttpChunkAggregator.messageReceived(HttpChunkAggregator.java:145)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
	at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
	at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296)
	at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:459)
	at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:536)
	at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435)
	at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
	at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
	at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268)
	at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255)
	at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88)
	at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108)
	at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337)
	at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89)
	at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178)
	at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
	at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)
TRACE 2021-03-08 19:17:57.459 [HTTPv2 Request Worker 28] net.pms.dlna.DLNAResource End of analysis for 2020 09 27

Not sure if this is how you files are organised or if UMS is creating this for the media library though. (probably the latter)

The first reference to "2020 09 27" is just after this SQL query which also has "(FILES.MODIFIED, 'yyyy MM d')" which could possibly be related.

Code: Select all

TRACE 2021-03-08 14:23:45.568 [HTTPv2 Request Worker 40] net.pms.dlna.virtual.MediaLibraryFolder genresSqls: [SELECT DISTINCT VIDEO_METADATA_GENRES.GENRE FROM FILES LEFT JOIN VIDEO_METADATA_GENRES ON FILES.FILENAME = VIDEO_METADATA_GENRES.FILENAME WHERE TYPE = 4 ORDER BY VIDEO_METADATA_GENRES.GENRE ASC, SELECT FORMATDATETIME(FILES.MODIFIED, 'yyyy MM d') FROM FILES LEFT JOIN VIDEO_METADATA_GENRES ON FILES.FILENAME = VIDEO_METADATA_GENRES.FILENAME WHERE VIDEO_METADATA_GENRES.GENRE = '${0}' AND TYPE = 4 ORDER BY FILES.MODIFIED DESC, SELECT FILES.FILENAME FROM FILES LEFT JOIN VIDEO_METADATA_GENRES ON FILES.FILENAME = VIDEO_METADATA_GENRES.FILENAME WHERE VIDEO_METADATA_GENRES.GENRE = '${1}' AND TYPE = 4 AND FORMATDATETIME(FILES.MODIFIED, 'yyyy MM d') = '${0}' ORDER BY FILES.FILENAME ASC]
TRACE 2021-03-08 14:23:45.568 [HTTPv2 Request Worker 40] net.pms.dlna.DLNAResource Adding new child "Filter by Information" with class "VirtualFolder"
TRACE 2021-03-08 14:23:45.568 [HTTPv2 Request Worker 40] net.pms.dlna.DLNAResource Adding new child "2020 09 27" with class "MediaLibraryFolder"

Looking at a browse request for another directory "###" does not have this error even though it looks identical.

Code: Select all

TRACE 2021-03-08 18:29:10.407 [HTTPv2 Request Worker 28] net.pms.configuration.RendererConfiguration Matched media renderer "[LG] webOS TV UN7300PTC" based on address 192.168.10.105
DEBUG 2021-03-08 18:29:10.407 [HTTPv2 Request Worker 28] net.pms.network.RequestHandlerV2 Recognized media renderer "[LG] webOS TV UN7300PTC"
TRACE 2021-03-08 18:29:10.408 [HTTPv2 Request Worker 28] net.pms.network.RequestHandlerV2 Received a browse request from [LG] webOS TV UN7300PTC [LG WebOS TV] (192.168.10.105:48842):

POST /upnp/control/content_directory HTTP/1.1

HEADER:
  SOAPAction: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
  DLNADeviceName.lge.com: %5bLG%5d%20webOS%20TV%20UN7300PTC
  User-Agent: Linux/4.4.84-612.21.6.jardine.2 UPnP/1.0 LGE WebOS TV LGE_DLNA_SDK/1.6.0/03.21.36 DLNADOC/1.50
  Host: 192.168.10.103:5001
  Content-Length: 679
  Content-Type: text/xml; charset="utf-8"

CONTENT:
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
  <s:Body>
    <u:Browse xmlns:u="urn:schemas-upnp-org:service:ContentDirectory:1">
      <ObjectID>30542</ObjectID>
      <BrowseFlag>BrowseDirectChildren</BrowseFlag>
      <Filter>res@resolution,res@nrAudioChannels,res@sampleFrequency,res@bitrate,dc:creator,res@dlna:cleartextSize,dc:date,upnp:genre,res,res@duration,res@size,upnp:albumArtURI,upnp:originalTrackNumber,upnp:album,upnp:artist,upnp:author</Filter>
      <StartingIndex>0</StartingIndex>
      <RequestedCount>30</RequestedCount>
      <SortCriteria/>
    </u:Browse>
  </s:Body>
</s:Envelope>

TRACE 2021-03-08 18:29:10.440 [HTTPv2 Request Worker 28] net.pms.dlna.virtual.MediaLibraryFolder 2 sqls2: [select FILENAME, MODIFIED from FILES F, AUDIOTRACKS A where F.ID = A.FILEID AND F.TYPE = 1 AND A.GENRE = '${2}' AND COALESCE(A.ALBUMARTIST, A.ARTIST) = '${1}' AND A.ALBUM = '${0}' ORDER BY A.TRACK ASC, F.FILENAME ASC]
TRACE 2021-03-08 18:29:10.440 [HTTPv2 Request Worker 28] net.pms.dlna.DLNAResource Adding new child "###" with class "MediaLibraryFolder"
TRACE 2021-03-08 18:29:10.441 [HTTPv2 Request Worker 28] net.pms.dlna.DLNAResource End of analysis for ###

except the first one references "net.pms.dlna.DLNAMediaDatabase" while the working one is "net.pms.dlna.virtual.MediaLibraryFolder"


I have no idea on what is wrong but have made an issue on GIT so the devs can make sense of it.

Does this have any side effects for you? or was it something you happened to notice in the logs?