OH, man sorry I misunderstood that issue. I have been starring at this for too long :)
Yes, that totally could be it. I'll apply that patch and should be able to confirm it or not. On Mon, Feb 26, 2018 at 1:02 PM, Mike Bayer <mike...@zzzcomputing.com> wrote: > On Mon, Feb 26, 2018 at 3:58 PM, Cecil Rock <cecil.r...@gmail.com> wrote: > > Yeah I saw those issues, but they did not seem like they would be > related to > > what we're seeing :( > > > > I had instrumented the identity_map earlier and could not catch an > instance > > where it was doing the wrong thing. The GC being guilty or maybe an > obscure > > bug higher in the stack feels more likely. It is helpful to know that a > bug > > doesn't come to mind with this. I'll see if I can mess with the GC and > run > > that to ground or not. If you have any other ideas they are much > > appreciated :) > > issue #4068 looks *very* likely to be related to what you are seeing. > I can't get your situation to reproduce with it however it is exactly > something that, in response to a garbage collection event, will remove > the *wrong* object from identity_map._dict and *keep* it in > identity_map._modified exactly as you are seeing. i might be able > to reproduce this simulating a GC against the object at a very > specific time during the load. > > > > > > On Mon, Feb 26, 2018 at 12:46 PM, Mike Bayer <mike...@zzzcomputing.com> > > wrote: > >> > >> On Mon, Feb 26, 2018 at 3:33 PM, Cecil Rock <cecil.r...@gmail.com> > wrote: > >> > Fairly old, v1.0.14. Its running in one of our older microservices. > >> > Once I > >> > understood what was going on, I went through the fix list and could > not > >> > find > >> > anything obviously related to it. We can't reproduce this at will and > >> > nothing obvious has changed, so we're worried that upgrading without > >> > understanding could just mask the issue if it exists. > >> > >> you are before the fix for > >> https://bitbucket.org/zzzeek/sqlalchemy/issues/4030 as well as > >> https://bitbucket.org/zzzeek/sqlalchemy/issues/4068 which both allow > >> the identity_map.discard(), safe_discard() and _fast_discard() methods > >> to be safer against race conditions. you'd want to get up to > >> version 1.1.14 to get away from each of these issues. > >> > >> there's a lot of ways I can break certain things to produce this error > >> on 1.0.14 but that same breakage still causes different errors > >> (because I'm purposely screwing up the internal state of things) in > >> later versions so I don't think I've isolated an exact race that can > >> cause this. > >> > >> > >> > >> > >> > > >> > On Monday, February 26, 2018 at 12:28:49 PM UTC-8, Mike Bayer wrote: > >> >> > >> >> um what version of SQLAlchemy is this? > >> >> > >> >> On Mon, Feb 26, 2018 at 3:22 PM, Cecil Rock <cecil...@gmail.com> > wrote: > >> >> > One of my thoughts was maybe the gc wiped out the identity_map and > it > >> >> > gets > >> >> > recreated empty. > >> >> > > >> >> > Here is a stack trace of when I detect the situation prior to the > >> >> > flush > >> >> > occurring. > >> >> > > >> >> >> [4018/eval_0/INFO/state/554/_modified_event] fc3a3a adding > >> >> >> <sqlalchemy.orm.state.InstanceState object at 0x7f6a5bb989e8> as > >> >> >> modified > >> >> >> inSession:False > >> >> >> [4018/eval_0/ERROR/evaluate/213/runEval] Evaluate job 4c4bdfaa > >> >> >> caught > >> >> >> exception, Oh Snap (Traceback (most recent call last): > >> >> >> File "/home/cecil/monkey/server/app/evaluate/evaluate.py", line > >> >> >> 207, > >> >> >> in > >> >> >> runEval > >> >> >> _evaluateMovie(params) > >> >> >> File "/home/cecil/monkey/server/app/evaluate/evaluate.py", line > >> >> >> 196, > >> >> >> in > >> >> >> _evaluateMovie > >> >> >> statusDetails=evalDetails) > >> >> >> File "/home/cecil/monkey/server/app/metrics/metricsUtils.py", > line > >> >> >> 230, > >> >> >> in updateRecordableEvent > >> >> >> event.statusDetails = statusDetails[0:MAX_STATUS_DETAILS] > >> >> >> File > >> >> >> > >> >> >> > >> >> >> "/home/cecil/monkey/server/venv/lib/python3.4/site- > packages/sqlalchemy/orm/attributes.py", > >> >> >> line 224, in __set__ > >> >> >> instance_dict(instance), value, None) > >> >> >> File > >> >> >> > >> >> >> > >> >> >> "/home/cecil/monkey/server/venv/lib/python3.4/site- > packages/sqlalchemy/orm/attributes.py", > >> >> >> line 702, in set > >> >> >> state._modified_event(dict_, self, old) > >> >> >> File > >> >> >> > >> >> >> > >> >> >> "/home/cecil/monkey/server/venv/lib/python3.4/site- > packages/sqlalchemy/orm/state.py", > >> >> >> line 556, in _modified_event > >> >> >> raise Exception('Oh Snap') > >> >> >> Exception: Oh Snap > >> >> >> ) > >> >> >> > >> >> >> This is what I'm looking at in _modified_event, this occurs after > >> >> >> the > >> >> >> sleep in the earlier example. > >> >> > > >> >> > instance_dict = self._instance_dict() > >> >> > if instance_dict: > >> >> > # ===DEBUGGING=== > >> >> > if isEvent: # just check objects of interest > >> >> > inSession = instance_dict.contains_state(self) > >> >> > logger.info('%s adding %s as modified > >> >> > inSession:%s', > >> >> > msgNum, self, inSession) > >> >> > if not inSession: > >> >> > raise Exception('Oh Snap') > >> >> > > >> >> > instance_dict._modified.add(self) > >> >> > > >> >> > Here is the stack trace if I don't catch this early > >> >> > > >> >> > [8370/eval_4/ERROR/evaluate/213/runEval] Evaluate job d498ba17 > caught > >> >> > exception, Over 100 subsequent flushes have occurred within > >> >> > session.commit() > >> >> > - is an after_flush() hook creating new objects? (Traceback (most > >> >> > recent > >> >> > call last): > >> >> > File "/home/cecil/monkey/server/app/evaluate/evaluate.py", line > >> >> > 207, > >> >> > in > >> >> > runEval > >> >> > _evaluateMovie(params) > >> >> > File "/home/cecil/monkey/server/app/evaluate/evaluate.py", line > >> >> > 196, > >> >> > in > >> >> > _evaluateMovie > >> >> > statusDetails=evalDetails) > >> >> > File "/home/cecil/monkey/server/app/metrics/metricsUtils.py", > line > >> >> > 288, in > >> >> > updateRecordableEvent > >> >> > addNotifEvent(event, > >> >> > workflowSequence=jobParams.get('workflowSequence')) > >> >> > File "/home/cecil/monkey/server/app/notification/notifUtils.py", > >> >> > line > >> >> > 93, > >> >> > in addNotifEvent > >> >> > db.session.commit() > >> >> > File > >> >> > > >> >> > > >> >> > "/home/cecil/monkey/server/venv/lib/python3.4/site- > packages/sqlalchemy/orm/scoping.py", > >> >> > line 157, in do > >> >> > return getattr(self.registry(), name)(*args, **kwargs) > >> >> > File > >> >> > > >> >> > > >> >> > "/home/cecil/monkey/server/venv/lib/python3.4/site- > packages/sqlalchemy/orm/session.py", > >> >> > line 822, in commit > >> >> > self.transaction.commit() > >> >> > File > >> >> > > >> >> > > >> >> > "/home/cecil/monkey/server/venv/lib/python3.4/site- > packages/sqlalchemy/orm/session.py", > >> >> > line 400, in commit > >> >> > self._prepare_impl() > >> >> > File > >> >> > > >> >> > > >> >> > "/home/cecil/monkey/server/venv/lib/python3.4/site- > packages/sqlalchemy/orm/session.py", > >> >> > line 383, in _prepare_impl > >> >> > "Over 100 subsequent flushes have occurred within " > >> >> > sqlalchemy.orm.exc.FlushError: Over 100 subsequent flushes have > >> >> > occurred > >> >> > within session.commit() - is an after_flush() hook creating new > >> >> > objects? > >> >> > > >> >> > > >> >> > > >> >> > > >> >> > > >> >> > -- > >> >> > 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 sqlalchemy+...@googlegroups.com. > >> >> > To post to this group, send email to sqlal...@googlegroups.com. > >> >> > Visit this group at https://groups.google.com/group/sqlalchemy. > >> >> > For more options, visit https://groups.google.com/d/optout. > >> > > >> > -- > >> > 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 sqlalchemy+unsubscr...@googlegroups.com. > >> > To post to this group, send email to sqlalchemy@googlegroups.com. > >> > Visit this group at https://groups.google.com/group/sqlalchemy. > >> > For more options, visit https://groups.google.com/d/optout. > >> > >> -- > >> 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 a topic in the > >> Google Groups "sqlalchemy" group. > >> To unsubscribe from this topic, visit > >> https://groups.google.com/d/topic/sqlalchemy/IcgPmdW6lz8/unsubscribe. > >> To unsubscribe from this group and all its topics, send an email to > >> sqlalchemy+unsubscr...@googlegroups.com. > >> To post to this group, send email to sqlalchemy@googlegroups.com. > >> Visit this group at https://groups.google.com/group/sqlalchemy. > >> For more options, visit https://groups.google.com/d/optout. > > > > > > > > > > -- > > - Cecil > > > > -- > > 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 sqlalchemy+unsubscr...@googlegroups.com. > > To post to this group, send email to sqlalchemy@googlegroups.com. > > Visit this group at https://groups.google.com/group/sqlalchemy. > > For more options, visit https://groups.google.com/d/optout. > > -- > 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 a topic in the > Google Groups "sqlalchemy" group. > To unsubscribe from this topic, visit https://groups.google.com/d/ > topic/sqlalchemy/IcgPmdW6lz8/unsubscribe. > To unsubscribe from this group and all its topics, send an email to > sqlalchemy+unsubscr...@googlegroups.com. > To post to this group, send email to sqlalchemy@googlegroups.com. > Visit this group at https://groups.google.com/group/sqlalchemy. > For more options, visit https://groups.google.com/d/optout. > -- - Cecil -- 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 sqlalchemy+unsubscr...@googlegroups.com. To post to this group, send email to sqlalchemy@googlegroups.com. Visit this group at https://groups.google.com/group/sqlalchemy. For more options, visit https://groups.google.com/d/optout.
