2015-12-08T18:54:44.293Z koa INFO <-- PUT /transfers/96d7b518-9571-473c-8c99-b35ab9c2c588
2015-12-08T18:54:44.316Z db DEBUG Executing (default): SELECT "primary", "name", "balance", "identity", "password", "public_key", "is_admin", "created_at", "updated_at" FROM "Accounts" AS "Account" WHERE "Account"."name" = 'asd' LIMIT 1;
2015-12-08T18:54:44.321Z transfers DEBUG putting transfer ID 96d7b518-9571-473c-8c99-b35ab9c2c588
2015-12-08T18:54:44.321Z transfers DEBUG asd -> asd : 1000
2015-12-08T18:54:44.322Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): START TRANSACTION;
2015-12-08T18:54:44.322Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;
2015-12-08T18:54:44.323Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): SET autocommit = 1;
2015-12-08T18:54:44.324Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): SELECT "id", "ledger", "debits", "credits", "part_of_payment", "state", "execution_condition", "execution_condition_fulfillment", "cancellation_condition", "cancellation_condition_fulfillment", "expires_at", "proposed_at", "pre_prepared_at", "prepared_at", "pre_executed_at", "executed_at", "rejected_at", "created_at", "updated_at" FROM "Transfers" AS "Transfer" WHERE "Transfer"."id" = '96d7b518-9571-473c-8c99-b35ab9c2c588';
2015-12-08T18:54:44.326Z updateState DEBUG updating transfer state from undefined to proposed
2015-12-08T18:54:44.341Z db DEBUG Executing (default): SELECT "primary", "name", "balance", "identity", "password", "public_key", "is_admin", "created_at", "updated_at" FROM "Accounts" AS "Account" WHERE "Account"."name" = 'asd' LIMIT 1;
2015-12-08T18:54:44.346Z db DEBUG Executing (default): SELECT "primary", "name", "balance", "identity", "password", "public_key", "is_admin", "created_at", "updated_at" FROM "Accounts" AS "Account" WHERE "Account"."name" = 'asd' LIMIT 1;
2015-12-08T18:54:44.348Z updateState DEBUG updating transfer state from proposed to pre_prepared
2015-12-08T18:54:44.353Z db DEBUG Executing (default): SELECT "primary", "name", "balance", "identity", "password", "public_key", "is_admin", "created_at", "updated_at" FROM "Accounts" AS "Account" WHERE "Account"."name" = 'hold' LIMIT 1;
2015-12-08T18:54:44.359Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): INSERT INTO "EntryGroups" ("updated_at","created_at") VALUES ('2015-12-08 18:54:44.358 +00:00','2015-12-08 18:54:44.358 +00:00') RETURNING *;
2015-12-08T18:54:44.361Z db DEBUG Executing (default): SELECT "primary", "name", "balance", "identity", "password", "public_key", "is_admin", "created_at", "updated_at" FROM "Accounts" AS "Account" WHERE "Account"."name" = 'asd' LIMIT 1;
2015-12-08T18:54:44.362Z account balances DEBUG sender asd balance: 3001 -> 2001
2015-12-08T18:54:44.364Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): INSERT INTO "Entries" ("entry_group","transfer_id","account","balance","updated_at","created_at") VALUES (95,'96d7b518-9571-473c-8c99-b35ab9c2c588',2,2001,'2015-12-08 18:54:44.363 +00:00','2015-12-08 18:54:44.363 +00:00') RETURNING *;
2015-12-08T18:54:44.368Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): UPDATE "Accounts" SET "balance"=2001,"updated_at"='2015-12-08 18:54:44.367 +00:00' WHERE "primary" = 2
2015-12-08T18:54:44.371Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): INSERT INTO "Entries" ("entry_group","transfer_id","account","balance","updated_at","created_at") VALUES (95,'96d7b518-9571-473c-8c99-b35ab9c2c588',22,-1850,'2015-12-08 18:54:44.370 +00:00','2015-12-08 18:54:44.370 +00:00') RETURNING *;
2015-12-08T18:54:44.374Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): UPDATE "Accounts" SET "balance"=-1850,"updated_at"='2015-12-08 18:54:44.373 +00:00' WHERE "primary" = 22
2015-12-08T18:54:44.375Z updateState DEBUG updating transfer state from pre_prepared to prepared
2015-12-08T18:54:44.375Z updateState DEBUG updating transfer state from prepared to pre_executed
2015-12-08T18:54:44.376Z db DEBUG Executing (default): SELECT "primary", "name", "balance", "identity", "password", "public_key", "is_admin", "created_at", "updated_at" FROM "Accounts" AS "Account" WHERE "Account"."name" = 'hold' LIMIT 1;
2015-12-08T18:54:44.378Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): INSERT INTO "EntryGroups" ("updated_at","created_at") VALUES ('2015-12-08 18:54:44.377 +00:00','2015-12-08 18:54:44.377 +00:00') RETURNING *;
2015-12-08T18:54:44.380Z db DEBUG Executing (default): SELECT "primary", "name", "balance", "identity", "password", "public_key", "is_admin", "created_at", "updated_at" FROM "Accounts" AS "Account" WHERE "Account"."name" = 'asd' LIMIT 1;
2015-12-08T18:54:44.382Z account balances DEBUG recipient asd balance: 3001 -> 4001
2015-12-08T18:54:44.386Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): INSERT INTO "Entries" ("entry_group","transfer_id","account","balance","updated_at","created_at") VALUES (96,'96d7b518-9571-473c-8c99-b35ab9c2c588',2,4001,'2015-12-08 18:54:44.383 +00:00','2015-12-08 18:54:44.383 +00:00') RETURNING *;
2015-12-08T18:54:44.395Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): UPDATE "Accounts" SET "balance"=4001,"updated_at"='2015-12-08 18:54:44.391 +00:00' WHERE "primary" = 2
2015-12-08T18:54:44.398Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): INSERT INTO "Entries" ("entry_group","transfer_id","account","balance","updated_at","created_at") VALUES (96,'96d7b518-9571-473c-8c99-b35ab9c2c588',22,-3850,'2015-12-08 18:54:44.397 +00:00','2015-12-08 18:54:44.397 +00:00') RETURNING *;
2015-12-08T18:54:44.405Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): UPDATE "Accounts" SET "balance"=-3850,"updated_at"='2015-12-08 18:54:44.403 +00:00' WHERE "primary" = 22
2015-12-08T18:54:44.406Z updateState DEBUG updating transfer state from pre_executed to executed
2015-12-08T18:54:44.406Z expiry monitor DEBUG unwatch transfer: 96d7b518-9571-473c-8c99-b35ab9c2c588
2015-12-08T18:54:44.415Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): INSERT INTO "Transfers" ("id","ledger","debits","credits","state","expires_at","proposed_at","pre_prepared_at","prepared_at","pre_executed_at","executed_at","updated_at","created_at") VALUES ('96d7b518-9571-473c-8c99-b35ab9c2c588','http://vahe-2.local:3000','[{"account":"asd","amount":"1000","authorized":true}]','[{"account":"asd","amount":"1000"}]','executed','2016-06-16 00:00:01.000 +00:00','2015-12-08 18:54:44.326 +00:00','2015-12-08 18:54:44.349 +00:00','2015-12-08 18:54:44.375 +00:00','2015-12-08 18:54:44.375 +00:00','2015-12-08 18:54:44.406 +00:00','2015-12-08 18:54:44.409 +00:00','2015-12-08 18:54:44.409 +00:00') RETURNING *;
2015-12-08T18:54:44.419Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): SELECT "id", "owner", "event", "subject", "target", "created_at", "updated_at" FROM "Subscriptions" AS "Subscription" WHERE (("Subscription"."event" = 'transfer.update' OR "Subscription"."event" = 'transfer.*' OR "Subscription"."event" = '*') AND "Subscription"."subject" IN ('http://vahe-2.local:3000/accounts/asd', 'http://vahe-2.local:3000/accounts/asd', '*'));
2015-12-08T18:54:44.422Z db DEBUG Executing (1c0a232a-b2b3-4342-bdbe-f2a380a173d9): COMMIT;
2015-12-08T18:54:44.425Z transfers DEBUG changes written to database
2015-12-08T18:54:44.425Z notificationWorker DEBUG scheduling notifications
2015-12-08T18:54:44.426Z koa INFO --> PUT /transfers/96d7b518-9571-473c-8c99-b35ab9c2c588 201 133ms -
2015-12-08T18:54:44.429Z db DEBUG Executing (default): SELECT "id", "subscription_id", "transfer_id", "retry_count", "retry_at", "created_at", "updated_at" FROM "Notifications" AS "Notification" WHERE ("Notification"."retry_at" IS NULL OR "Notification"."retry_at" < '2015-12-08 18:54:44.427 +00:00');