search

CommonGarden / Grow-Hub

An extensible gateway controller for Hydroponics, Aquaponics, Terrariums, Grow-Tents, Bioreactors, and more!
BSD 2-Clause "Simplified" License
7 stars 1 forks source link

MPhydro offline issues #12

Closed catbarph closed 6 years ago

catbarph commented 6 years ago

Device went offline just after 1AM on 2018/07/05.

First, there was a lot of these errors in forever.log:

{ isClientSafe: true,
  error: 500,
  reason: 'Internal server error',
  message: 'Internal server error [500]',
  errorType: 'Meteor.Error' } undefined

Then this kind of thing happened frequently:

Error: pigpio error -1 in gpioInitialise
at initializePigpio (/home/pi/Grow-Hub/driver/node_modules/pigpio/pigpio.js:11:12)
at new Gpio (/home/pi/Grow-Hub/driver/node_modules/pigpio/pigpio.js:25:3)
at new DigitalOutput (/home/pi/Grow-Hub/driver/node_modules/raspi-gpio/dist/index.js:79:25)
at RaspiIOCore.value (/home/pi/Grow-Hub/driver/node_modules/raspi-io-core/dist/index.js:560:38)
at RaspiIOCore.pinMode (/home/pi/Grow-Hub/driver/node_modules/raspi-io-core/dist/index.js:512:21)
at /home/pi/Grow-Hub/driver/node_modules/raspi-io-core/dist/index.js:434:17
at Array.forEach (<anonymous>)
at /home/pi/Grow-Hub/driver/node_modules/raspi-io-core/dist/index.js:360:32
at _combinedTickCallback (internal/process/next_tick.js:131:7)
at process._tickDomainCallback (internal/process/next_tick.js:218:9)
error: Forever detected script exited with code: 1
error: Script restart attempt #9609
1530807553449 Available RaspberryPi-IO
2018-07-05 09:19:13 initInitialise: bind to port 8888 failed (Address already in use)
/home/pi/Grow-Hub/driver/node_modules/pigpio/pigpio.js:11
pigpio.gpioInitialise();
^

Then, after remote reboot, some of these:

[ '23.11',
'54.47',
'1018.64',
'295',
'21.1999969482',
'67.51',
'232',
'472',
'\'LOW\'',
'98\n' ]
Air Temperature: 23.11
Humidity: 54.47
Pressure: 1018.64
Lux: 295
ph: 4.774
Conductivity: 733.3
Water Temperature: 21.2037786549
Bed Temperature: 21.1999969482
Bed Humidity: 67.51
Flow rate 1: 232
Flow rate 2: 472
Water level: 'LOW'
Water level (etape): 98
{ isClientSafe: true,
error: 500,
reason: 'Internal server error',
message: 'Internal server error [500]',
errorType: 'Meteor.Error' } undefined

Then back to the first:

{ isClientSafe: true,
  error: 500,
  reason: 'Internal server error',
  message: 'Internal server error [500]',
  errorType: 'Meteor.Error' } undefined

FYI I've renamed forever.log a few times, to make it easier to view...

catbarph commented 6 years ago

MPhydro offline @ 1AM on 7/5

JakeHartnell commented 6 years ago

And the server error, where the problem took place:

Exception while invoking method 'Thing.emit' { MongoError: quota exceeded
    at resultHandler (/var/app/current/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/bulk/ordered.js:459:11)
    at /var/app/current/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:544:18
    at _combinedTickCallback (internal/process/next_tick.js:131:7)
    at process._tickDomainCallback (internal/process/next_tick.js:218:9)
  name: 'BulkWriteError',
  message: 'quota exceeded',
  driver: true,
  code: 12501,
  index: 0,
  errmsg: 'quota exceeded',
  getOperation: [Function],
  toJSON: [Function],
  toString: [Function],
  result: 
   BulkWriteResult {
     ok: [Getter],
     nInserted: [Getter],
     nUpserted: [Getter],
     nMatched: [Getter],
     nModified: [Getter],
     nRemoved: [Getter],
     getInsertedIds: [Function],
     getUpsertedIds: [Function],
     getUpsertedIdAt: [Function],
     getRawResponse: [Function],
     hasWriteErrors: [Function],
     getWriteErrorCount: [Function],
     getWriteErrorAt: [Function],
     getWriteErrors: [Function],
     getLastOp: [Function],
     getWriteConcernError: [Function],
     toJSON: [Function],
     toString: [Function],
     isOk: [Function] } }
Exception while polling query {"collectionName":"Events","selector":{},"options":{"transform":null}} { MongoError: collection dropped between getMore calls
    at /var/app/current/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:598:61
    at authenticateStragglers (/var/app/current/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:516:16)
    at Connection.messageHandler (/var/app/current/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:552:5)
    at emitMessageHandler (/var/app/current/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/connection.js:309:10)
    at Socket.<anonymous> (/var/app/current/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/connection.js:452:17)
    at emitOne (events.js:115:13)
    at Socket.emit (events.js:210:7)
    at addChunk (_stream_readable.js:266:12)
    at readableAddChunk (_stream_readable.js:253:11)
    at Socket.Readable.push (_stream_readable.js:211:10)
    at TCP.onread (net.js:585:20)
 => awaited here:
    at Function.Promise.await (/var/app/current/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
    at Promise.asyncApply (packages/mongo/mongo_driver.js:1034:11)
    at /var/app/current/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
 => awaited here:
    at Promise.await (/var/app/current/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:60:12)
    at SynchronousCursor._nextObject (packages/mongo/mongo_driver.js:1083:12)
    at SynchronousCursor.forEach (packages/mongo/mongo_driver.js:1097:22)
    at SynchronousCursor.getRawObjects (packages/mongo/mongo_driver.js:1146:12)
    at PollingObserveDriver._pollMongo (packages/mongo/polling_observe_driver.js:153:44)
    at Object.task (packages/mongo/polling_observe_driver.js:90:12)
    at Meteor._SynchronousQueue.SQp._run (packages/meteor.js:872:16)
    at packages/meteor.js:849:12
  name: 'MongoError',
  message: 'collection dropped between getMore calls',
  ok: 0,
  errmsg: 'collection dropped between getMore calls',
  code: 96,
  codeName: 'OperationFailed' }

We ran out of free tier database space again. Anyway, we have the event data in influx, I cleared out the mongo event collection again and we should be good to go for a little while.

catbarph commented 6 years ago

Still is being an issue. No data has been logged in Grafana since 11:26AM (worked for about two hours). I renamed the last forever.log to foreveroldJuly2018.log, rebooted, and am getting a lot of this sort of output now:

[ '22.59',
  '51.21',
  '1020',
  '0',
  '19.8999977111',
  '66.52',
  '248',
  '472',
  '\'LOW\'',
  '98\n' ]
[ '22.59',
  '51.2',
  '1019.98',
  '0',
  '19.9099998474',
  '66.39',
  '248',
  '472',
  '\'LOW\'',
  '98\n' ]
Air Temperature: 22.59
Humidity: 51.2
Pressure: 1019.98
Lux: 0
ph: 4.844
Conductivity: 813.8
Water Temperature: 25.3284263158
Bed Temperature: 19.9099998474
Bed Humidity: 66.39
Flow rate 1: 248
Flow rate 2: 472
Water level: 'LOW'
Water level (etape): 98
[ '22.59',
  '51.19',
  '1019.99',
  '0',
  '19.9099998474',
  '66.33',
  '248',
  '472',
  '\'LOW\'',
  '98\n' ]

After reboot, the camera sent at least one new picture to the webapp, but all the data in the dashboard is from several hours ago and is not updating there or in Grafana.

JakeHartnell commented 6 years ago

Again it was the database (the were > 400 mb worth of jobs documents which I removed and repaired the database.), it's working now. We should prioritize getting a more permanent solution for this problem.

JakeHartnell commented 6 years ago

When you see the 500 error, that means it's a server issue (not a Grow-Hub issue).