Oops. . .wrong log entries for the postgres log. They should look like this:
2017-06-28 12:02:39.547 MDT [4456] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:02:39.548 MDT [4456] richard@stemp LOG: unexpected EOF on
client connection with an open transaction
2017-06-28 12:07:51.871 MDT [4756] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:07:51.874 MDT [4757] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:07:51.874 MDT [4755] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:07:51.877 MDT [4758] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:10:51.732 MDT [5014] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:10:51.734 MDT [5015] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:10:51.738 MDT [5012] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:10:51.745 MDT [5013] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:16:23.471 MDT [5515] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:16:23.476 MDT [5514] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:16:23.476 MDT [5513] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:16:23.478 MDT [5516] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:22:29.631 MDT [5902] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:22:29.634 MDT [5903] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:22:29.635 MDT [5904] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:22:29.636 MDT [5905] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:27:21.487 MDT [6255] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:27:21.491 MDT [6253] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:27:21.493 MDT [6256] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:27:21.499 MDT [6254] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:27:45.262 MDT [6339] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:27:45.262 MDT [6338] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:27:45.264 MDT [6340] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:27:45.269 MDT [6341] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:34:13.243 MDT [6701] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:34:13.245 MDT [6699] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:34:13.248 MDT [6700] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:34:13.252 MDT [6702] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:43:06.143 MDT [7177] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:43:06.145 MDT [7179] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:43:06.150 MDT [7178] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:43:06.150 MDT [7176] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:43:06.150 MDT [7176] richard@stemp LOG: unexpected EOF on
client connection with an open transaction
2017-06-28 12:55:12.279 MDT [7843] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:55:12.285 MDT [7844] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:55:12.286 MDT [7841] richard@stemp LOG: could not receive
data from client: Connection reset by peer
2017-06-28 12:55:12.288 MDT [7842] richard@stemp LOG: could not receive
data from client: Connection reset by peer
On Wednesday, June 28, 2017 at 1:16:52 PM UTC-6, Richard Rosenberg wrote:
>
>
> Hello:
>
> I've run into a problem with SQLA's implementation of postgresql's upsert.
> The equivalent statement works fine when run as a straight up query (thru
> pgadmin).
>
> The model(s) in question:
>
> class TileUpd(Base):
> __tablename__ = 'tile_upd'
> __table_args__ = TARGS
> hostname = Column(PgD.TEXT, ForeignKey('edgenode.hostname'),
> primary_key=True)
> groupip = Column(PgD.INET, primary_key=True)
> portnum = Column(PgD.INTEGER, primary_key=True)
> sourceip = Column(PgD.INET, nullable=False)
> timecreated = Column(PgD.TIMESTAMP, nullable=False,
> server_default=text('current_timestamp'))
> timesent = Column(PgD.TIMESTAMP, nullable=True)
>
> class TileSub(Base):
> __tablename__ = 'tile_sub'
> __table_args__ = TARGS
> groupip = Column(PgD.INET, primary_key=True)
> portnum = Column(PgD.INTEGER, primary_key=True)
> sourceip = Column(PgD.INET, nullable=False)
> hostname = Column(PgD.TEXT, ForeignKey('edgenode.hostname'),
> nullable=False)
> timecreated = Column(PgD.TIMESTAMP, nullable=False,
> server_default=text('current_timestamp'))
>
> This is a pyramid app, so I (so far) am using the canned transaction
> manager, though I prefer to control commits explicitly.
>
>
> from sqlalchemy.dialects.postgresql import insert as UPSERT
>
> #scaler change loader/endpoint - no json, uses POST
> @view_config(route_name='loader', renderer='json')
> def loader_view(request: pyramid.request):
> """Waits for scaled tile information from scaler cluster and loads
> changes
> into postgresql"""
> logger.debug("loader view")
> if request.params.get("event_type", None) == "ssm_source":
> this_time = time.time()
> REG = request.registry
> b_interval = float(REG.settings.get('batch_interval', .25))
> group, port = request.params.get("group", ":").split(":")
> source = request.params.get("source", None)
> ##############################################
> ## POSTGRES goes here, route and write for all
> ## subscribers in tile_sub
> ##############################################
> sess = request.dbsession
> ##upsert for tile updates
> subsq =
> sess.query(TileSub).filter(TileSub.groupip==group).filter(TileSub.portnum==port)
> updl = []
> updstable = TileUpd.__table__
> updtime = datetime.datetime.now()
> for tsub in subsq.all():
> instmt = UPSERT(updstable).values(
> hostname=tsub.hostname,
> groupip=group,
> portnum=int(port),
> sourceip=source
> ).on_conflict_do_update(
> constraint = updstable.primary_key,
> set_ = dict(sourceip=source, timecreated=updtime)
> )
> sess.execute(instmt)
> transaction.commit()
>
> The statements appear to be well formed, but SQLA logs show a rollback for
> every call to execute:
>
> 2017-06-28 12:55:12,136 INFO
> [sqlalchemy.engine.base.Engine:679][MainThread] BEGIN (implicit)
> 2017-06-28 12:55:12,137 INFO
> [sqlalchemy.engine.base.Engine:1140][MainThread] SELECT tile_sub.groupip AS
> tile_sub_groupip, tile_sub.portnum AS tile_sub_portnum, tile_sub.sourceip
> AS tile_sub_sourceip, tile_sub.hostname AS tile_sub_hostname,
> tile_sub.timecreated AS tile_sub_timecreated
> FROM tile_sub
> WHERE tile_sub.groupip = %(groupip_1)s AND tile_sub.portnum = %(portnum_1)s
> 2017-06-28 12:55:12,137 INFO
> [sqlalchemy.engine.base.Engine:1143][MainThread] {'groupip_1':
> '239.129.237.126', 'portnum_1': '55002'}
> 2017-06-28 12:55:12,139 INFO
> [sqlalchemy.engine.base.Engine:1140][MainThread] INSERT INTO tile_upd
> (hostname, groupip, portnum, sourceip) VALUES (%(hostname)s, %(groupip)s,
> %(portnum)s, %(sourceip)s) ON CONFLICT ON CONSTRAINT pk_tile_upd DO UPDATE
> SET sourceip = %(param_1)s, timecreated = %(param_2)s
> 2017-06-28 12:55:12,139 INFO
> [sqlalchemy.engine.base.Engine:1143][MainThread] {'hostname':
> 'localhost:8080', 'groupip': '239.129.237.126', 'portnum': 55002,
> 'sourceip': '172.28.190.54', 'param_1': '172.28.190.54', 'param_2':
> datetime.datetime(2017, 6, 28, 12, 55, 12, 135541)}
> 2017-06-28 12:55:12,140 INFO
> [sqlalchemy.engine.base.Engine:699][MainThread] ROLLBACK
> 0.0.0.0 - - [28/Jun/2017 12:55:12] "POST /loader HTTP/1.1" 200 17
> 2017-06-28 12:55:12,148 DEBUG [stempqm.views.qmviews:42][MainThread]
> loader view
> 2017-06-28 12:55:12,149 INFO
> [sqlalchemy.engine.base.Engine:679][MainThread] BEGIN (implicit)
> 2017-06-28 12:55:12,150 INFO
> [sqlalchemy.engine.base.Engine:1140][MainThread] SELECT tile_sub.groupip AS
> tile_sub_groupip, tile_sub.portnum AS tile_sub_portnum, tile_sub.sourceip
> AS tile_sub_sourceip, tile_sub.hostname AS tile_sub_hostname,
> tile_sub.timecreated AS tile_sub_timecreated
> FROM tile_sub
> WHERE tile_sub.groupip = %(groupip_1)s AND tile_sub.portnum = %(portnum_1)s
> 2017-06-28 12:55:12,151 INFO
> [sqlalchemy.engine.base.Engine:1143][MainThread] {'groupip_1':
> '239.129.237.128', 'portnum_1': '55002'}
> 2017-06-28 12:55:12,153 INFO
> [sqlalchemy.engine.base.Engine:1140][MainThread] INSERT INTO tile_upd
> (hostname, groupip, portnum, sourceip) VALUES (%(hostname)s, %(groupip)s,
> %(portnum)s, %(sourceip)s) ON CONFLICT ON CONSTRAINT pk_tile_upd DO UPDATE
> SET sourceip = %(param_1)s, timecreated = %(param_2)s
> 2017-06-28 12:55:12,153 INFO
> [sqlalchemy.engine.base.Engine:1143][MainThread] {'hostname':
> 'localhost:8080', 'groupip': '239.129.237.128', 'portnum': 55002,
> 'sourceip': '172.28.190.64', 'param_1': '172.28.190.64', 'param_2':
> datetime.datetime(2017, 6, 28, 12, 55, 12, 149604)}
> 2017-06-28 12:55:12,154 INFO
> [sqlalchemy.engine.base.Engine:699][MainThread] ROLLBACK
>
> All of the log entries look OK, with the exception of the failure to
> commit. However, the postgresql logs show the following:
>
> 2017-06-27 23:48:42.308 MDT [2913] richard@stemp STATEMENT: INSERT INTO
> tile_upd (hostname, groupip, portnum, sourceip, timesent) VALUES
> ('localhost:8080', '239.129.235.37', '55002', '172.28.190.42', NULL)
> 2017-06-27 23:48:42.331 MDT [2914] richard@stemp ERROR: duplicate key
> value violates unique constraint "pk_tile_upd"
> 2017-06-27 23:48:42.331 MDT [2914] richard@stemp DETAIL: Key (hostname,
> groupip, portnum)=(localhost:8080, 239.129.236.128, 55002) already exists.
> 2017-06-27 23:48:42.331 MDT [2914] richard@stemp STATEMENT: INSERT INTO
> tile_upd (hostname, groupip, portnum, sourceip, timesent) VALUES
> ('localhost:8080', '239.129.236.128', '55002', '172.28.190.69', NULL)
> 2017-06-27 23:48:42.346 MDT [2912] richard@stemp ERROR: duplicate key
> value violates unique constraint "pk_tile_upd"
> 2017-06-27 23:48:42.346 MDT [2912] richard@stemp DETAIL: Key (hostname,
> groupip, portnum)=(localhost:8080, 239.129.236.201, 55002) already exists.
> 2017-06-27 23:48:42.346 MDT [2912] richard@stemp STATEMENT: INSERT INTO
> tile_upd (hostname, groupip, portnum, sourceip, timesent) VALUES
> ('localhost:8080', '239.129.236.201', '55002', '172.28.190.75', NULL)
> 2017-06-27 23:48:42.403 MDT [2912] richard@stemp ERROR: duplicate key
> value violates unique constraint "pk_tile_upd"
> 2017-06-27 23:48:42.403 MDT [2912] richard@stemp DETAIL: Key (hostname,
> groupip, portnum)=(localhost:8080, 239.129.237.19, 55002) already exists.
> 2017-06-27 23:48:42.403 MDT [2912] richard@stemp STATEMENT: INSERT INTO
> tile_upd (hostname, groupip, portnum, sourceip, timesent) VALUES
> ('localhost:8080', '239.129.237.19', '55002', '172.28.190.65', NULL)
> 2017-06-27 23:48:42.468 MDT [2912] richard@stemp ERROR: duplicate key
> value violates unique constraint "pk_tile_upd"
>
>
> Additionally, I can run the equivalent statement from pgadmin just fine:
>
> INSERT INTO tile_upd
> (hostname, groupip, portnum, sourceip)
> VALUES ('localhost:8080', '239.129.135.40', 55002, '172.28.190.50')
> ON CONFLICT ON CONSTRAINT pk_tile_upd DO UPDATE SET timecreated =
> current_timestamp, timesent = NULL, sourceip = '172.28.190.50';
>
> Query returned successfully: one row affected, 24 msec execution time.
>
> I am absolutely puzzled, but it seems likely that pyramid_tm is in the way
> somehow. It always wants to do its own thing, and calling commit explicitly
> is something it seems to abhor. My next step is to wrap this in:
>
> with transaction.manager as tx:
>
> But this is really not what I want. I'm tempted to rip out all of the
> zopish stuff and go with SQLA's session, but before I try that, I thought
> it might be worthwhile to get some further information.
>
> This is python3.6, pg 9.6, pyramid 1.9b, and pyramid_tm 2.1 running on
> stock debian.
>
> Thanks for any insights. I'd hate to start over due to something like
> this. . .
>
> Richard
>
--
SQLAlchemy -
The Python SQL Toolkit and Object Relational Mapper
http://www.sqlalchemy.org/
To post example code, please provide an MCVE: Minimal, Complete, and Verifiable
Example. See http://stackoverflow.com/help/mcve for a full description.
---
You received this message because you are subscribed to the Google Groups
"sqlalchemy" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To post to this group, send email to [email protected].
Visit this group at https://groups.google.com/group/sqlalchemy.
For more options, visit https://groups.google.com/d/optout.
