FeathersJS Inserts 2 records into MySql from 1 REST call

[wilsonweb]

When I use the .create(item) method to do an INSERT from the client (within the browser) I see 1 call via websocket or REST go to feathersjs. I see one request go into Feathersjs. For an unknown reason I see 2 rows created in MySql and 2 lines in the log that say: {"message":"after: name_of_service - Method: create","level":"info"}

Using sequelize 4.42.0 and feathers-sequelize 6.0.1

I do not have the issue when running create() from within the server code, only from client.

I found feathersjs-ecosystem/feathers-rethinkdb#80 that looked simular but is for a different DB and the explanation did not fit with MySql.

I switched to MariaDB for other reasons but obviously nothing changed.

I was using FeathersJS v3.x and upgrading to v4.x to see if that would fix it. Nope. As I work around I have been making my own insert methods but it would be nice to use the built in ones.

I tried switching between REST and websocket.

My Hooks:

const { authenticate } = require('@feathersjs/authentication').hooks;

module.exports = {
  before: {
    all: [ ], // authenticate('jwt') normally use, but deactivated to debug
    find: [],
    get: [],
    create: [],
    update: [],
    patch: [],
    remove: []
  },

  after: {
    all: [],
    find: [],
    get: [],
    create: [],
    update: [],
    patch: [],
    remove: []
  },

  error: {
    all: [],
    find: [],
    get: [],
    create: [],
    update: [],
    patch: [],
    remove: []
  }
};

Service:

const createService = require('feathers-sequelize');
const createModel = require('../../models/name_of_service.model');
const hooks = require('./name_of_service.hooks');

module.exports = function (app) {
    const Model = createModel(app);
    const paginate = app.get('paginate');

    const options = {
	Model,
	paginate: {
	    default: 100,
	    max: 2000
	}
    };
 
    app.use('/name_of_service', createService(options));
 
    const service = app.service('name_of_service');

    service.hooks(hooks);
};

I expected it to insert 1 row in MySql table. But got 2. I expected one row in the log for the after hook, but see 2. This has been happening for a couple of months and was thinking, hey, maybe I am not the only one.

[daffl]

I can't see this happening by default so a complete example to reproduce would be the best way to be able to look into it.

[edwardsmarkf]

dumb question, but have you turned on the sequelize debugging? then you will see all the SQL statements. Thank you, Mark Edwards

…

On Sun, Sep 22, 2019 at 6:12 PM David Luecke ***@***.***> wrote: I can't see this happening by default so a complete example to reproduce would be the best way to be able to look into it. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#321?email_source=notifications&email_token=AAWJ3YUM5OBML2KDYU3MNN3QLAJXDA5CNFSM4IXPTW4KYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD7JTQLQ#issuecomment-533936174>, or mute the thread </~https://github.com/notifications/unsubscribe-auth/AAWJ3YUSTW55YYLVOL4VXWTQLAJXDANCNFSM4IXPTW4A> .

[wilsonweb]

dumb question, but have you turned on the sequelize debugging? then you will see all the SQL statements. Thank you, Mark Edwards
…
On Sun, Sep 22, 2019 at 6:12 PM David Luecke @.***> wrote: I can't see this happening by default so a complete example to reproduce would be the best way to be able to look into it. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#321?email_source=notifications&email_token=AAWJ3YUM5OBML2KDYU3MNN3QLAJXDA5CNFSM4IXPTW4KYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD7JTQLQ#issuecomment-533936174>, or mute the thread /~https://github.com/notifications/unsubscribe-auth/AAWJ3YUSTW55YYLVOL4VXWTQLAJXDANCNFSM4IXPTW4A .

Yup, that shows 2 inserts, or, as I am seeing today too, 2 UPDATE statements. This log block shows what happens with one call from this.get().service.patch(this.get().order_notes.id, obj)

{"message":"after: users - Method: get","level":"info"}
{"message":"after: users - Method: get","level":"info"}
Executing (default): UPDATE `order_notes` SET `ecomdash_id`=35832728,`notes`='test',`refund_notes`='paid in pennies',`refund_amount`=9.99,`refund_date`='2019-10-08 00:00:00',`reason`='Unverified Customer',`refund_req_date`=NULL,`updatedAt`='2019-09-24 18:13:45' WHERE (`id` = 35832728)
{"message":"after: users - Method: get","level":"info"}
{"message":"after: users - Method: get","level":"info"}
Executing (default): UPDATE `order_notes` SET `ecomdash_id`=35832728,`notes`='test',`refund_notes`='paid in pennies',`refund_amount`=9.99,`refund_date`='2019-10-08 00:00:00',`reason`='Unverified Customer',`refund_req_date`=NULL,`updatedAt`='2019-09-24 18:13:45' WHERE (`id` = 35832728)
Executing (default): SELECT `id`, `ecomdash_id`, `reason`, `notes`, `refund_notes`, `refund_amount`, `refund_date`, `refund_req_date`, `createdAt`, `updatedAt` FROM `order_notes` AS `order_notes` WHERE (`order_notes`.`id` = 35832728) AND `order_notes`.`id` IN (35832728);
Executing (default): SELECT `id`, `ecomdash_id`, `reason`, `notes`, `refund_notes`, `refund_amount`, `refund_date`, `refund_req_date`, `createdAt`, `updatedAt` FROM `order_notes` AS `order_notes` WHERE (`order_notes`.`id` = 35832728) AND `order_notes`.`id` IN (35832728);
{"message":"after: order_notes - Method: patch","level":"info"}
{"message":"after: order_notes - Method: patch","level":"info"}

[daffl]

This looks like a mistake somewhere in your application logic but it's difficult to say without a complete example to reproduce the issue.

[wilsonweb]

This looks like a mistake somewhere in your application logic but it's difficult to say without a complete example to reproduce the issue.

ok, thank you. I'll try and make a slimmed down single model version of my app to put on github.

[edwardsmarkf]

weird - is there some issue with an ALL hook that is being executed twice or something like that? Thank you, Mark Edwards

…

On Tue, Sep 24, 2019 at 11:21 AM Jason Wilson ***@***.***> wrote: This looks like a mistake somewhere in your application logic but it's difficult to say without a complete example to reproduce the issue. ok, thank you. I'll try and make a slimmed down single model version of my app to put on github. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#321?email_source=notifications&email_token=AAWJ3YRQUZQKVCALGCTMFQTQLJLCPA5CNFSM4IXPTW4KYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD7PKMEY#issuecomment-534685203>, or mute the thread </~https://github.com/notifications/unsubscribe-auth/AAWJ3YWZWWBXIEIW633GJ7LQLJLCPANCNFSM4IXPTW4A> .

[wilsonweb]

Thank you everyone for your help. I found the issue.
I fixed my rookie mistake by changing:

app.configure(socketio());
app.configure(socketio(function(io) {io.sockets.setMaxListeners(555);}));

To:

app.configure(socketio(function(io) {io.sockets.setMaxListeners(555);}));