better logging

master
Henry Jameson 2 months ago
parent 5cbac57d4d
commit 396d60fca2
  1. 13
      .gitignore
  2. 117
      index.js
  3. 17
      nfc.js
  4. 17
      statemachine.js
  5. 36
      statuslogger.js
  6. 17
      yacardemu.js

13
.gitignore vendored

@ -0,0 +1,13 @@
.DS_Store
.idea
*.log
tmp/
*.tern-port
node_modules/
npm-debug.log*
yarn-debug.log*
yarn-error.log*
*.tsbuildinfo
.npm
.eslintcache

@ -1,6 +1,8 @@
import { program } from 'commander'
import chalk from 'chalk'
import {
Feedback,
DisplayController,
Logger,
INSTRUCTIONS,
CARD_PRESENT,
GUEST_PLAYING,
@ -23,30 +25,31 @@ program.parse();
const opts = program.opts()
const saves = opts.cardsLocation
const logger = Feedback({ bus: opts.i2cBus, noLCD: opts.noLCD })
const logger = Logger(chalk.green('[EABU]'))
const lcd = DisplayController({ bus: opts.i2cBus, noLCD: opts.noLCD })
if (opts.noLCD) {
logger.info('[EABU]: Skipping LCD initialization on user\'s request')
logger.info('Skipping LCD initialization on user\'s request')
} else if (opts.i2cBus) {
logger.initLCD()
lcd.initLCD()
} else {
logger.error('[EABU]: No i2c bus is specified, nor --noLCD is used, aborting')
logger.error('No i2c bus is specified, nor --noLCD is used, aborting')
process.exit(1)
}
if (!(opts.emulatorPort > 0)) {
logger.error('[EABU]: Emulator port not configured!')
logger.error('Emulator port not configured!')
process.exit(1)
}
if (!(opts.cardsLocation.length > 0)) {
logger.error('[EABU]: Saves location not set!')
logger.error('Saves location not set!')
process.exit(1)
}
const port = opts.emulatorPort
logger.info('[EABU]: Starting up')
logger.info('Starting up')
const sm = wmmt3()
const status = {
@ -59,8 +62,7 @@ const countDown = (secs, callback) => {
status.countdown = secs
status.countdownCallback = callback
const func = () => {
console.debug(status.countdown)
logger.setCountdown(status.countdown)
lcd.setCountdown(status.countdown)
if (status.countdown > 0) {
status.countdown--
status.countdownTimeoutId = setTimeout(func, 1000)
@ -74,53 +76,53 @@ const countDown = (secs, callback) => {
func()
}
logger.info('[EABU]: Starting YACE api')
logger.info('Starting YACE api')
const yace = YACE(port)
yace.once('error', () => setTimeout(() => {
yace.startPolling()
logger.error('[YACE]: Emulator unavailable, retrying in 1 sec')
logger.error('Emulator unavailable, retrying in 1 sec')
}, 1000))
yace.startPolling()
const onInit = () => {
logger.info('[YACE]: Ready for new play.')
logger.info('Ready for new play.')
yace.once('shutter-opened', () => {
sm.shutterOpen()
})
}
logger.info('[EABU]: Initializing NFC (if this hangs check if pcscd is running)')
const nfc = ICCard(logger, saves)
logger.info('Initializing NFC (if this hangs check if pcscd is running)')
const nfc = ICCard(saves)
nfc.alt.on('new-card', () => {
if (sm.cannot('new-card')) {
logger.warn('[YACE]: Cannot prepare new card when game\'s not ready for it!')
logger.warn('Cannot prepare new card when game\'s not ready for it!')
switch (sm.state) {
case 'playing':
logger.setMessage(CARD_PRESENT)
lcd.setMessage(CARD_PRESENT)
break
case 'guest-playing':
logger.setMessage(GUEST_PLAYING)
lcd.setMessage(GUEST_PLAYING)
break
default:
logger.setMessage(INSTRUCTIONS)
lcd.setMessage(INSTRUCTIONS)
}
}
})
nfc.alt.on('old-card', () => {
if (sm.cannot('old-card')) {
logger.warn('[YACE]: Cannot insert card when game\'s not ready for it!')
logger.warn('Cannot insert card when game\'s not ready for it!')
switch (sm.state) {
case 'playing':
logger.setMessage(CARD_PRESENT)
lcd.setMessage(CARD_PRESENT)
break
case 'guest-playing':
logger.setMessage(GUEST_PLAYING)
lcd.setMessage(GUEST_PLAYING)
break
default:
logger.setMessage(INSTRUCTIONS)
lcd.setMessage(INSTRUCTIONS)
}
}
})
@ -137,28 +139,31 @@ sm.observe('onLeaveState', () => {
})
sm.observe('onEnterState', (state) => {
console.log(state.to)
logger.setState(state.to)
lcd.setState(state.to)
})
sm.observe('onReadyCard', () => {
logger.info('[YACE]: Shutter opened!')
logger.info('Shutter opened, assuming game started!')
// countDown(10, () => {
yace.once('shutter-closed', () => {
logger.info('[YACE]: No card scanned!')
logger.info('No card scanned!')
sm.timeout()
})
countDown(20, () => {
logger.info('Shutter still open after 20 seconds, assuming invalid state and resetting...')
sm.goto('idle')
})
nfc.once('new-card', (id) => {
yace.prepareCard(id)
logger.setCardId(id)
lcd.setCardId(id)
sm.newCard()
})
nfc.once('old-card', (id) => {
yace.insertCard(id)
logger.setCardId(id)
lcd.setCardId(id)
sm.oldCard()
})
@ -167,66 +172,70 @@ sm.observe('onReadyCard', () => {
// GUEST PLAY
sm.observe('onGpWaitDispense', () => {
countDown(30, () => {
logger.info('[YACE]: No card dispensed, assuming real guest play.')
logger.info('No card dispensed, assuming real guest play.')
sm.timeout()
})
yace.once('card-dispensed', () => {
logger.info('[YACE]: Guest card dispensed')
logger.info('Guest card dispensed')
sm.dispense()
})
})
sm.observe('onGuestPlaying', () => {
logger.warn('[YACE]: Guest game in progress')
logger.warn('Guest game in progress')
yace.once('card-ejected', () => {
logger.info('[YACE]: Card ejected, guest game over.')
logger.setMessage(THANKS_FOR_PLAYING)
logger.info('Card ejected, guest game over.')
lcd.setMessage(THANKS_FOR_PLAYING)
sm.eject()
yace.prepareCard('dummy')
logger.setCardId('')
lcd.setCardId('')
})
})
// REGISTERED CARD
sm.observe('onOcCheckRenewal', () => {
logger.info('[YACE]: Card inserted, waiting in case renewal is needed')
logger.info('Card inserted, waiting in case renewal is needed')
// XXX if card is corrupt or whatever it will be ejected outright.
// this wouldn't be a problem if we knew beforehand if renewal is needed
// or not.
yace.once('card-ejected', () => {
logger.info('[YACE]: Card ejected, renewal detected.')
logger.setMessage(RENEW_CARD)
logger.info('Card ejected, renewal detected.')
lcd.setMessage(RENEW_CARD)
sm.eject()
})
countDown(20, () => {
logger.info('[YACE]: No card ejected, no renewal detected.')
countDown(60, () => {
logger.info('No card ejected, no renewal detected.')
sm.timeout()
})
})
sm.observe('onOcWaitDispense', () => {
logger.info('[YACE]: Present card ejected (and discarded ;_;), waiting for new card to be dispensed')
logger.info('Present card ejected (and discarded ;_;), waiting for new card to be dispensed')
yace.once('card-dispensed', () => {
logger.info('[YACE]: Renewed card dispensed')
logger.info('Renewed card dispensed')
sm.dispense()
})
yace.once('card-ejected', () => {
logger.warn('[YACE]: Card ejected again, not sure what\'s going on, resetting...')
logger.warn('Card ejected again, not sure what\'s going on, resetting...')
sm.goto('idle')
})
countDown(30, () => {
logger.warn('[YACE]: Error: not dispensed within 30 seconds, assuming illegal state and resetting')
logger.warn('Error: not dispensed within 30 seconds, assuming illegal state and resetting')
sm.goto('idle')
})
})
// UNREGISTERED CARD
sm.observe('onNcWaitShutter', () => {
logger.info('[YACE]: Waiting for shutter to close')
logger.info('Waiting for shutter to close')
yace.once('shutter-closed', () => {
sm.shutterClose()
@ -234,29 +243,29 @@ sm.observe('onNcWaitShutter', () => {
})
sm.observe('onNcWaitDispense', () => {
logger.info('[YACE]: "No card" is selected, waiting for card purchase')
logger.info('"No card" is selected, waiting for card purchase')
yace.once('card-dispensed', () => {
logger.info('[YACE]: New card dispensed!')
logger.info('New card dispensed!')
sm.dispense()
})
countDown(30, () => {
logger.warn('[YACE]: Error: not dispensed within 30 seconds, assuming guest play')
logger.setMessage(REGISTR_ABORT)
logger.warn('Error: not dispensed within 30 seconds, assuming guest play')
lcd.setMessage(REGISTR_ABORT)
sm.timeout()
})
})
// CARD GAME OVER
sm.observe('onPlaying', () => {
logger.info('[YACE]: Game in progress')
logger.info('Game in progress')
yace.once('card-ejected', () => {
logger.warn('[YACE]: Card ejected, game over.')
logger.warn('Card ejected, game over.')
yace.prepareCard('dummy')
logger.setCardId('')
logger.setMessage(THANKS_FOR_PLAYING)
lcd.setCardId('')
lcd.setMessage(THANKS_FOR_PLAYING)
sm.eject()
})
})

@ -1,35 +1,38 @@
import { NFC } from 'nfc-pcsc'
import { Logger } from './statuslogger.js'
import chalk from 'chalk'
import EventEmitter from 'events'
import fs from 'fs'
export const ICCard = (logger, path) => {
export const ICCard = (path) => {
const logger = Logger(chalk.magenta('[PCSC]'))
const nfc = new NFC()
const emitter = new EventEmitter()
emitter.alt = new EventEmitter()
nfc.on('error', err => {
logger.error('[PCSC]:', err);
logger.error('Error', err);
});
nfc.on('reader', reader => {
logger.info('[PCSC]: Card reader found: ' + reader)
logger.info('Card reader found: ' + reader.name)
reader.on('card', card => {
logger.info(`[PCSC]: Card ${card.uid} scanned`)
logger.info(`Card ${card.uid} scanned`)
if (!fs.existsSync(path + card.uid + '.track_0')) {
logger.info('[PCSC]: Data for card uid not found, assuming new')
logger.info('Data for card uid not found, assuming new')
emitter.alt.emit('new-card', card.uid)
emitter.emit('new-card', card.uid)
} else {
logger.info('[PCSC]: Data for card uid found!')
logger.info('Data for card uid found!')
emitter.alt.emit('old-card', card.uid )
emitter.emit('old-card', card.uid )
}
})
reader.on('error', err => {
logger.error('[PCSC] ', err);
logger.error('Error', err);
});
})

@ -1,7 +1,12 @@
import { Logger } from './statuslogger.js'
import chalk from 'chalk'
import StateMachine from 'javascript-state-machine'
//import visualize from 'javascript-state-machine/lib/visualize.js'
export const wmmt3 = () => new StateMachine({
export const wmmt3 = () => {
const logger = Logger(chalk.red('[WMMT3]'))
return new StateMachine({
init: 'idle',
transitions: [
// Game sends signal that shutter is open
@ -32,7 +37,13 @@ export const wmmt3 = () => new StateMachine({
// Emergency reset
{ name: 'goto', from: '*', to: function(s) { return s } }
]
],
methods: {
onEnterState (state) {
logger.debug('Entered state ' + chalk.bold(state.to))
}
}
})
}
//console.log(visualize(WMMT3CardSM))
//console.log(visualize(WMMT3CardSM))

@ -5,6 +5,7 @@ let lcd
const err = chalk.bold.redBright
const inf = chalk.blueBright
const wrn = chalk.yellowBright
const dbg = chalk.dim.gray
const SPIN_CHARS = [
[0x14,0x1c,0x15,0x1,0x6,0x0,0x00,0x0],
@ -102,7 +103,26 @@ export const THANKS_FOR_PLAYING = [
'time. t. hj',
]
export const Feedback = ({ bus, noLCD }) => {
export const Logger = (prefix) => {
return {
warn(...string) {
console.warn(wrn('[!]') + prefix + ' ' + string.join(' '))
},
info(...string) {
console.info(inf('[ ]') + prefix + ' ' + string.join(' '))
},
error(...string) {
console.error(err('[!]') + prefix + ' ' + err(string.join(' ')))
},
debug(...string) {
console.error(dbg('[ ]' + prefix + ' ' + string.join(' ')))
}
}
}
export const DisplayController = ({ bus, noLCD }) => {
const logger = Logger(chalk.blue('[LCD]'))
const status = {
hasLCD: false,
spinnerIndex: 0,
@ -138,7 +158,6 @@ export const Feedback = ({ bus, noLCD }) => {
}
const statusLineGenerator = () => {
console.log(status.countdown)
let countdownI = status.countdown > 0
? `${status.countdown}`.padStart(3, ' ')
: ' '
@ -177,17 +196,8 @@ export const Feedback = ({ bus, noLCD }) => {
setCardId(cardId) {
status.cardId = cardId
},
warn(...string) {
console.warn(wrn('[!]') + ' ' + string.join(' '))
},
info(...string) {
console.info(inf('[ ]') + ' ' + string.join(' '))
},
error(...string) {
console.error(err('[!]') + ' ' + string.join(' '))
},
initLCD() {
this.info('Initializing LCD...')
logger.info('Initializing LCD...')
const loop = () => {
const buffer = bufferGen()
@ -210,7 +220,7 @@ export const Feedback = ({ bus, noLCD }) => {
.begin()
.then(() => {
status.hasLCD = true
this.info('LCD Initialized!')
logger.info('LCD Initialized!')
lcd.clearSync()
lcd.printLineSync(0, 'Wangan Midnight ')
lcd.printLineSync(1, ' Maximum Tune 3DX+')

@ -1,7 +1,12 @@
import fetch from 'node-fetch'
import chalk from 'chalk'
import EventEmitter from 'events'
import { Logger } from './statuslogger.js'
export const YACE = (port) => {
const logger = Logger(chalk.yellow('[YACE]'))
const emitter = new EventEmitter()
const status = {
hasCard: false,
@ -18,15 +23,20 @@ export const YACE = (port) => {
fetch(`http://127.0.0.1:${port}/api/v1/hasCard`)
.then(res => res.json())
.then(bool => {
if (!status.emulatorRunning) {
logger.info('Card emulator connection established')
}
status.emulatorRunning = true
if (status.hasCard !== bool) {
if (bool) {
logger.debug('Card inserted or dispensed')
// No disambiguation right now
emitter.alt.emit('card-inserted')
emitter.alt.emit('card-dispensed')
emitter.emit('card-inserted')
emitter.emit('card-dispensed')
} else {
logger.debug('Card ejected')
emitter.alt.emit('card-ejected')
emitter.emit('card-ejected')
}
@ -48,9 +58,11 @@ export const YACE = (port) => {
status.emulatorRunning = true
if (status.shutterOpen !== bool) {
if (bool) {
logger.debug('Shutter opened')
emitter.alt.emit('shutter-opened')
emitter.emit('shutter-opened')
} else {
logger.debug('Shutter closed')
emitter.alt.emit('shutter-closed')
emitter.emit('shutter-closed')
}
@ -64,17 +76,18 @@ export const YACE = (port) => {
}
emitter.startPolling = () => {
logger.info('Initializing YACardEmu polling')
pollShutterStatus()
pollCardStatus()
}
emitter.prepareCard = (id) => {
console.log('preparing', id)
logger.debug('Preparing card ' + id)
return fetch(`http://127.0.0.1:${port}/api/v1/insertedCard?loadonly=true&cardname=` + id, { method: 'POST' })
}
emitter.insertCard = (id) => {
console.log('inserting', id)
logger.debug('Inserting card ' + id)
return fetch(`http://127.0.0.1:${port}/api/v1/insertedCard?cardname=` + id, { method: 'POST' })
}

Loading…
Cancel
Save