Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ODatabaseException reported by console.bat application, apparently session times out while query is in flight #8733

Closed
MironAtHome opened this issue Jan 19, 2019 · 17 comments

Comments

@MironAtHome
Copy link

OrientDB Version: 3.0.12

Java Version: 9

OS: Microsoft Windows 10 Enterprise Edition

Expected behavior

I think an well respected protocol is to let query run as long as it takes, at least in dedicated applications, such as console.

Actual behavior

Steps to reproduce

orientdb {db=GEO}> SELECT FROM ( SELECT NAME, COUNT(*) AS ROW_COUNT FROM City GROUP BY NAME ) WHERE ROW_COUNT > 1

Error: com.orientechnologies.orient.core.exception.ODatabaseException: No query with id '1547909386535_5509' found probably expired session
DB name="GEO"
DB name="GEO"

Note

After reconnecting to database an re - launching query it succeeded. So, the issue didn't reproduce.

@luigidellaquila
Copy link
Member

hi @MironAtHome

Are you in remote? Did you stop and restart OrientDB after connecting on the console?

Thanks

Luigi

@MironAtHome
Copy link
Author

Nope, I was all the time in console application and after some interval in issuing queries ( perhaps 15 - 25 minutes ) issued one, that ended with the exception as per above.
Yes, I was signed in by issuing line "connect remote:localhost/GEO root password"
After query failed, as per above, I re - issued same line "connect remote:localhost/GEO root password" and re - executed same query. This time same ( rather long running ) query completed without exception.

@creisle
Copy link

creisle commented Jul 29, 2019

I am also having this error message pop up, but I am using orientjs. It appears when I perform queries that return a significant number of records consecutively (I am paginating through records in a class through an api)

No query with id '1564419754632_4879233' found probably expired session

I can fix it by restarting the API application and therefore the db connection, however it means the queries fail in the mean time and the api temporarily crashes

My specs are
orientdb version: 3.0.22
java version: 10
os: centos07
nodejs: 10.13.0
orientjs: 3.0.5

@petervavro
Copy link

The same here with orientjs. In my case, I perform queries in a loop. Requesting at least 30 ("SELECT ...") queries right after each other. I have to restart to get rid of this.

@wolf4ood
Copy link
Member

Hi @petervavro @creisle

do you have a way to reproduce this, so i can debug it?

@creisle which api are you using for paginating the class?

Thanks

@petervavro
Copy link

petervavro commented Jul 31, 2019

Imagine, I run following query at least 30 times in the loop, but in every query, I am changing date ("2019-07-01T05:00:00.000Z") to (day + 1), in other words, one query for every day of the month.

This is my js which generating the SQL :

  async checkAvailability ({ rules, filters }) {

    let since = new Date(filters.since.getTime())
    let until = new Date(filters.until.getTime())

    let days = []

    // Sanitize empty string because OrientDB throws error.
    rules = rules.map((rule) => {

      if (typeof rule.since !== 'undefined' && rule.since === '') delete rule.since
      if (typeof rule.until !== 'undefined' && rule.until === '') delete rule.until

      return rule

    })

    // eslint-disable-next-line no-unmodified-loop-condition
    for (var d = since; d <= until; d.setDate(d.getDate() + 1)) {

      let dateToCheck = new Date(d)

      let r = this.db
        .select([
          `$daysToCheck[${this.generateOperationSQL(dateToCheck, true)}].size() as inOperation`,
          `$daysToCheck[${this.generateOperationSQL(dateToCheck, false)}].size() as notInOperation`
        ])
        .from(this.tableName)

      r = r.let(`$daysToCheck`, this.db.rawExpression(`
        list(${JSON.stringify(rules)})
      `))

      console.log(r.toString())

      // Get records
      let result = await r.all()

      days.push({
        day: dateToCheck,
        displayed: (result[0].inOperation > 0 && result[0].notInOperation === 0)
      })

    }

    return days

  }

Query:

SELECT $daysToCheck[
      (
        (notInOperation IS NOT DEFINED OR notInOperation=false)
        AND (
          (
            since IS NOT DEFINED AND until IS NOT DEFINED
              ) OR (
            since IS DEFINED AND until IS NOT DEFINED AND ( DATE("2019-07-01T05:00:00.000Z") >= since )
              ) OR (
            since IS DEFINED AND until IS DEFINED AND ( DATE("2019-07-01T05:00:00.000Z") BETWEEN since AND until )
          )
        ) AND (
          (
            
      (
        since IS DEFINED AND ( DATE("2019-07-01T05:00:00.000Z") >= since )
        AND 
        ordinal IS DEFINED 
        AND (
          (
            round(
              (DATE("2019-07-01T05:00:00.000Z").asLong() - since.asLong()) / 86400000
            )  % ordinal
          ) = 0
        )
        
        ) AND NOT (
          dayTypeRestriction IS DEFINED AND dayTypeRestriction="always-not-on-holiday"
        ) AND (
          (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="always"
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction=""
          ) OR (
            dayTypeRestriction IS NOT DEFINED
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="on-holiday-only"
          )
      
      )
    
              ) OR (
            
      (
        month IS DEFINED AND month=7
      ) AND (
        day IS DEFINED AND day=1
      )
    
              ) OR (
            
        (
          weekday IS NOT DEFINED 
        ) AND (
          onHoliday IS DEFINED AND onHoliday=TRUE
        )
      
              ) OR (
            
      (
        weekday IS DEFINED 
        AND 
        weekday=1 
        
        ) AND NOT (
          dayTypeRestriction IS DEFINED AND dayTypeRestriction="always-not-on-holiday"
        ) AND (
          (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="always"
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction=""
          ) OR (
            dayTypeRestriction IS NOT DEFINED
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="on-holiday-only"
          )
      
        
      ) AND NOT (
        (
          afterHolidayRestriction IS DEFINED AND afterHolidayRestriction="only"
        )
    
      )
    
              ) OR (
            
      (
        weekday IS NOT DEFINED 
        AND 
        month IS NOT DEFINED 
        AND 
        day IS NOT DEFINED 
        AND 
        ordinal IS NOT DEFINED 
        AND 
        onHoliday=true
      )
    
              ) OR (
            
      (
        specialTimeRange IS DEFINED AND specialTimeRange IN $specialTimeRanges.id.asList()
        
        ) AND NOT (
          dayTypeRestriction IS DEFINED AND dayTypeRestriction="always-not-on-holiday"
        ) AND (
          (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="always"
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction=""
          ) OR (
            dayTypeRestriction IS NOT DEFINED
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="on-holiday-only"
          )
      
      )
    
              ) OR (
            
      specialDay IS DEFINED AND specialDay IN $specialDays.id.asList()
    
          )
        ) AND active=TRUE
      )
    ].size() as inOperation, $daysToCheck[
      (
        (notInOperation IS NOT DEFINED OR notInOperation=true)
        AND (
          (
            since IS NOT DEFINED AND until IS NOT DEFINED
              ) OR (
            since IS DEFINED AND until IS NOT DEFINED AND ( DATE("2019-07-01T05:00:00.000Z") >= since )
              ) OR (
            since IS DEFINED AND until IS DEFINED AND ( DATE("2019-07-01T05:00:00.000Z") BETWEEN since AND until )
          )
        ) AND (
          (
            
      (
        since IS DEFINED AND ( DATE("2019-07-01T05:00:00.000Z") >= since )
        AND 
        ordinal IS DEFINED 
        AND (
          (
            round(
              (DATE("2019-07-01T05:00:00.000Z").asLong() - since.asLong()) / 86400000
            )  % ordinal
          ) = 0
        )
        
        ) AND NOT (
          dayTypeRestriction IS DEFINED AND dayTypeRestriction="always-not-on-holiday"
        ) AND (
          (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="always"
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction=""
          ) OR (
            dayTypeRestriction IS NOT DEFINED
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="on-holiday-only"
          )
      
      )
    
              ) OR (
            
      (
        month IS DEFINED AND month=7
      ) AND (
        day IS DEFINED AND day=1
      )
    
              ) OR (
            
        (
          weekday IS NOT DEFINED 
        ) AND (
          onHoliday IS DEFINED AND onHoliday=TRUE
        )
      
              ) OR (
            
      (
        weekday IS DEFINED 
        AND 
        weekday=1 
        
        ) AND NOT (
          dayTypeRestriction IS DEFINED AND dayTypeRestriction="always-not-on-holiday"
        ) AND (
          (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="always"
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction=""
          ) OR (
            dayTypeRestriction IS NOT DEFINED
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="on-holiday-only"
          )
      
        
      ) AND NOT (
        (
          afterHolidayRestriction IS DEFINED AND afterHolidayRestriction="only"
        )
    
      )
    
              ) OR (
            
      (
        weekday IS NOT DEFINED 
        AND 
        month IS NOT DEFINED 
        AND 
        day IS NOT DEFINED 
        AND 
        ordinal IS NOT DEFINED 
        AND 
        onHoliday=true
      )
    
              ) OR (
            
      (
        specialTimeRange IS DEFINED AND specialTimeRange IN $specialTimeRanges.id.asList()
        
        ) AND NOT (
          dayTypeRestriction IS DEFINED AND dayTypeRestriction="always-not-on-holiday"
        ) AND (
          (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="always"
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction=""
          ) OR (
            dayTypeRestriction IS NOT DEFINED
          ) OR (
            dayTypeRestriction IS DEFINED AND dayTypeRestriction="on-holiday-only"
          )
      
      )
    
              ) OR (
            
      specialDay IS DEFINED AND specialDay IN $specialDays.id.asList()
    
          )
        ) AND active=TRUE
      )
    ].size() as notInOperation FROM OperationalDays LET $daysToCheck = 
        list([{"notInOperation":false,"weekday":4,"since":"2019-07-28T05:00:00.000Z","active":true,"id":"#88:57"},{"notInOperation":false,"weekday":6,"since":"2019-07-28T05:00:00.000Z","active":true,"id":"#82:59"},{"notInOperation":false,"weekday":1,"since":"2019-07-28T05:00:00.000Z","active":true,"id":"#85:59"}])

Btw, If you know how to do a better query please let me know, I really appreciate it. Also, I think it might be the solution to prevent the issue.

Based on what I read, I believe it might have something to do with orientjs, what do you think?

@wolf4ood
Copy link
Member

wolf4ood commented Aug 1, 2019

Hi @petervavro @creisle

are you using a pool of sessions or a single session?

Thanks

@creisle
Copy link

creisle commented Aug 1, 2019

I am using a single session. I 'think' I am using the newer API. I am using session.query

My queries are simpler. more like

select from someclass where deleted is null skip 1000 limit 1000

I am not able to reliably reproduce this yet unfortunately. It is an intermittent problem

@wolf4ood
Copy link
Member

wolf4ood commented Aug 1, 2019

@creisle

do you by any chance call session.close() before the query is finished?

@creisle
Copy link

creisle commented Aug 1, 2019

@wolf4ood no, it is not called

@wolf4ood
Copy link
Member

wolf4ood commented Aug 5, 2019

Hi @creisle @petervavro

i'm trying to replicate it with stress tests without luck. Could you check if there is some exception in the server logs?

Thanks

@creisle
Copy link

creisle commented Aug 9, 2019

I haven't been able to find anything in the server logs but there seem to be 2 factors that coincide with it happening: high memory usage on the server, and a pause after lots of requests (insert/delete/update etc) in a row

I do have the full error message that I get back from orientjs tho. Not sure if its helpful or not

2019-08-08T23:24:45.079Z debug: No query with id '1565306685072_804270' found probably expired session
	DB name="next-production"
{ OrientDB.RequestError: No query with id '1565306685072_804270' found probably expired session
	DB name="<NAME>"
    at child.Operation.parseError (/home/creisle/git/test/node_modules/orientjs/lib/client/network/protocol37/operation.js:1224:13)
    at child.Operation.consume (/home/creisle/test/node_modules/orientjs/lib/client/network/protocol37/operation.js:566:35)
    at ONetworkConnection.Connection.process (/home/creisle/test/node_modules/orientjs/lib/client/network/conn.js:462:17)
    at ONetworkConnection.Connection.handleSocketData (/home/creisle/test/node_modules/orientjs/lib/client/network/conn.js:344:20)
    at Socket.emit (events.js:182:13)
    at addChunk (_stream_readable.js:283:12)
    at readableAddChunk (_stream_readable.js:264:11)
    at Socket.Readable.push (_stream_readable.js:219:10)
    at TCP.onStreamRead [as onread] (internal/stream_base_commons.js:94:17)
From previous event:
    at ONetworkConnection.Connection._sendOp (/home/creisle/test/node_modules/orientjs/lib/client/network/conn.js:80:10)
    at ONetworkConnection.Connection.send (/home/creisletest/node_modules/orientjs/lib/client/network/conn.js:65:17)
    at withRetrySession.resource (/home/creisle/test/node_modules/orientjs/lib/client/database/session.js:166:27)
    at acquire.then.resource (/home/creisle/test/node_modules/orientjs/lib/client/database/session.js:179:18)
    at runCallback (timers.js:705:18)
    at tryOnImmediate (timers.js:676:5)
    at processImmediate (timers.js:658:5)
From previous event:
    at Promise (/home/creisle/git/test/node_modules/orientjs/lib/client/database/session.js:177:10)
From previous event:
    at SessionManager.withSession (/home/creisle/test/node_modules/orientjs/lib/client/database/session.js:172:12)
    at Promise (/home/creisle/test/node_modules/orientjs/lib/client/database/session.js:200:12)
From previous event:
    at SessionManager.withRetrySession (/home/creisle/test/node_modules/orientjs/lib/client/database/session.js:199:12)
    at SessionManager.send (/home/creisle/test/node_modules/orientjs/lib/client/database/session.js:148:17)
    at ODatabaseSession.send (/home/creisle/test/node_modules/orientjs/lib/client/database/database.js:52:32)
    at child.readBoolean.data (/home/creisle/test/node_modules/orientjs/lib/client/network/protocol37/operations/query.js:138:12)
    at child.Operation.parseBoolean (/home/creisle/test/node_modules/orientjs/lib/client/network/protocol37/operation.js:739:12)
    at child.Operation.consume (/home/creisle/test/node_modules/orientjs/lib/client/network/protocol37/operation.js:566:35)
    at ONetworkConnection.Connection.process (/home/creisle/test/node_modules/orientjs/lib/client/network/conn.js:462:17)
    at ONetworkConnection.Connection.handleSocketData (/home/creisle/test/node_modules/orientjs/lib/client/network/conn.js:344:20)
    at Socket.emit (events.js:182:13)
    at addChunk (_stream_readable.js:283:12)
    at readableAddChunk (_stream_readable.js:264:11)
    at Socket.Readable.push (_stream_readable.js:219:10)
    at TCP.onStreamRead [as onread] (internal/stream_base_commons.js:94:17)
  name: 'OrientDB.RequestError',
  message:
   'No query with id \'1565306685072_804270\' found probably expired session\r\n\tDB name="next-production"',
  data: {},
  isMVCC: [Function],
  isTokenException: [Function],
  previous: [],
  code: 5,
  identifier: 0,
  id: 1,
  type:
   'com.orientechnologies.orient.core.exception.ODatabaseException',
  hasMore: 0,
  level: 'debug',
  timestamp: '2019-08-08T23:24:45.079Z',
  [Symbol(level)]: 'debug',
  [Symbol(message)]:
   '2019-08-08T23:24:45.079Z debug: No query with id \'1565306685072_804270\' found probably expired session\r\n\tDB name="<NAME>"' }

@creisle
Copy link

creisle commented Aug 16, 2019

Have you had any luck debugging this? Its happening semi-regularly for me now. I've also noticed in the last couple of versions of the 3.0.X series that the web application logs me out very fast and I have to re-login a lot (similar to #8600). Do you think they are related?

@TheWizl
Copy link

TheWizl commented Aug 20, 2019

I cannot login to the demodb at all. Session expired. Using studio v3.0.22. Can access the studio page but not login remotely by ip or by localhost.

@wolf4ood
Copy link
Member

Hi @creisle @petervavro

good news i've reproduced the issue, so now i can work on a fix.

Thanks

@wolf4ood
Copy link
Member

Hi @creisle @petervavro

i've just pushed a fix for orientjs and publish a new version

#9012

It should solve the issue

@creisle
Copy link

creisle commented Sep 25, 2019

thank you!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

No branches or pull requests

7 participants