title: Difference in sequence of query generated in Django and Postgres for select_for_update
body: <p>I'm facing a strange situation, where sequence of query logged in Django and Postgres is different when using <code>select_for_update()</code> inside <code>transaction.atomic()</code> block.</p>
  
  <p>Basically I've a <code>ModelForm</code> where I'm validating the <code>cleaned_data</code> against the database, for duplicate request. And then in create view's <code>form_valid()</code> method, I'm saving the instance. To have both the operation inside same transaction, I'm overriding <code>post()</code> method, and wrapping those two method calls inside <code>transaction.atomic()</code>.</p>
  
  <p>Here's the code for whatever I said above:</p>
  
  <pre><code># Form
  class MenuForm(forms.ModelForm):
      def __init__(self, *args, **kwargs):
          user_id = kwargs.pop('user_id', None)
          super(MenuForm, self).__init__(*args, **kwargs)
  
      def clean(self):
          cleaned_data = super(MenuForm, self).clean()
          dish_name = cleaned_data.get('dish_name')
          menus = Menu.objects.select_for_update().filter(user_id=self.user_id)
  
          for menu in menus:
              if menu.dish_name == dish_name:
                  self.add_error('dish_name', 'Dish already exists')
                  return cleaned_data
          return cleaned_data
  
  # CreateView
  class MenuCreateView(CreateView):
      form_class = MenuForm
  
      def get_form_kwargs(self):
          kwargs = super(MenuCreateView, self).get_form_kwargs()
          kwargs.update({'user_id': self.request.session.get('user_id')})
          return kwargs
  
      def form_valid(self, form):
          user = User.objects.get(id=self.request.session.get('user_id'))
          form.instance.user = user
          return super(MenuCreateView, self).form_valid(form)
  
      def post(self, request, *args, **kwargs):
          form = self.get_form()
  
          with transaction.atomic():
              if form.is_valid():
                  return self.form_valid(form)
              else:
                  return self.form_invalid(form)
  </code></pre>
  
  <p>Now suppose I fire two request at the same time, to create a menu with same dish. I expect the second request to fail. But, both of them are passing. It looks like, the second transaction is not seeing the changes done in previous transaction. Because of which, the total <code>menus</code> remain the same in both the transaction that is returned by <code>select_for_update()</code>.</p>
  
  <p>Given that Postgres default Isolation level is <code>READ COMMITTED</code>, I expect the changes to be visible. So, I tried logging the queries to see that COMMIT; is fired at right time. Here's the query log by django and in postgres:</p>
  
  <h2>Django Log:</h2>
  
  <pre><code>SELECT "menu"."id", "menu"."dish_id", "menu"."dish_name" FROM "menu" WHERE ("menu"."dish_name" = "Test Dish") FOR UPDATE; args=("Test Dish")    
  INSERT INTO "menu" ("dish_id", "dish_name") VALUES (2, "Test Dish") RETURNING "menu"."id"; args=(2, "Test Dish")
  SELECT "menu"."id", "menu"."dish_id", "menu"."dish_name" FROM "menu" WHERE ("menu"."dish_name" = "Test Dish") FOR UPDATE; args=("Test Dish")
  INSERT INTO "menu" ("dish_id", "dish_name") VALUES (2, "Test Dish") RETURNING "menu"."id"; args=(2, "Test Dish")
  </code></pre>
  
  <h2>Postgres Log:</h2>
  
  <pre><code>&lt;2016-03-18 17:55:46.176 IST  0  2/31  56ebf3ca.aac0&gt;LOG:  statement: SHOW default_transaction_isolation
  &lt;2016-03-18 17:55:46.177 IST  0  2/32  56ebf3ca.aac0&gt;LOG:  statement: SET TIME ZONE 'UTC'
  &lt;2016-03-18 17:55:46.178 IST  0  2/33  56ebf3ca.aac0&gt;LOG:  statement: SELECT t.oid, typarray
      FROM pg_type t JOIN pg_namespace ns
          ON typnamespace = ns.oid
      WHERE typname = 'hstore';
  
  &lt;2016-03-18 17:55:46.182 IST  0  2/34  56ebf3ca.aac0&gt;LOG:  statement: BEGIN
  &lt;2016-03-18 17:55:46.301 IST  0  3/2  56ebf3ca.aac1&gt;LOG:  statement: SHOW default_transaction_isolation
  &lt;2016-03-18 17:55:46.302 IST  0  3/3  56ebf3ca.aac1&gt;LOG:  statement: SET TIME ZONE 'UTC'
  &lt;2016-03-18 17:55:46.302 IST  0  3/4  56ebf3ca.aac1&gt;LOG:  statement: SELECT t.oid, typarray
      FROM pg_type t JOIN pg_namespace ns
          ON typnamespace = ns.oid
      WHERE typname = 'hstore';
  
  &lt;2016-03-18 17:55:46.312 IST  0  3/5  56ebf3ca.aac1&gt;LOG:  statement: BEGIN
  &lt;2016-03-18 17:55:46.963 IST  0  3/5  56ebf3ca.aac1&gt;LOG:  statement: SELECT "menu"."id", "menu"."dish_id", "menu"."dish_name" FROM "menu" 
  WHERE ("menu"."dish_name" = "Test Dish") FOR UPDATE
  &lt;2016-03-18 17:55:46.964 IST  0  2/34  56ebf3ca.aac0&gt;LOG:  statement: SELECT "menu"."id", "menu"."dish_id", "menu"."dish_name" FROM "menu" 
  WHERE ("menu"."dish_name" = "Test Dish") FOR UPDATE
  &lt;2016-03-18 17:55:47.040 IST  23712  3/5  56ebf3ca.aac1&gt;LOG:  statement: INSERT INTO "menu" ("dish_id", "dish_name") VALUES (2, "Test Dish")RETURNING "menu"."id"
  &lt;2016-03-18 17:55:47.061 IST  23712  3/5  56ebf3ca.aac1&gt;LOG:  statement: COMMIT
  &lt;2016-03-18 17:55:47.229 IST  23713  2/34  56ebf3ca.aac0&gt;LOG:  statement: INSERT INTO "menu" ("dish_id", "dish_name") VALUES (2, "Test Dish")RETURNING "menu"."id"
  &lt;2016-03-18 17:55:47.231 IST  23713  2/34  56ebf3ca.aac0&gt;LOG:  statement: COMMIT
  </code></pre>
  
  <h2>Postgres.conf:</h2>
  
  <pre><code>max_connections = 100
  log_destination = 'stderr'
  logging_collector = on
  log_directory = 'pg_log'
  log_line_prefix = '&lt;%m  %x  %v  %c&gt;'
  log_statement = 'all'
  </code></pre>
  
  <p>As you can see, the order of SELECT and INSERT queries in not the same in both the logs. I'm unable to understand why this would happen. Also, if you notice, the session_id for the SELECT queries in Postgres log is different. Could that explain something here?</p>
  
  <p>And if this is expected behaviour, how could I solve the core issue here? Avoid concurrent INSERT queries, based on existing record.</p>
  
  <h2><strong>UPDATE</strong>:</h2>
  
  <p>I didn't mention that the actual logic to ignore duplicate menu is not just based on dish name. The one above is simplified example. </p>
  
  <p>Considering menu model as:</p>
  
  <pre><code>class Menu:
      user_id = models.IntegerField()
      dish = models.ForeignKey(Dish)
      order_start_time = models.DateTimeField()
      order_end_time = models.DateTimeField()
  </code></pre>
  
  <p>The actual logic goes like this:</p>
  
  <ul>
  <li>Fetch all menu with the <code>dish_name</code> from db.</li>
  <li>Check the <code>order_start_time</code> and <code>order_end_time</code> for all the those menu, and see if any of them overlaps with the <code>order_start_time</code> and <code>order_end_time</code> for the new menu. If conflict found, avoid addition.</li>
  </ul>
  
  <p>So, we can add two menu for dish - <code>d1</code>, having order window - <code>[9am-10am]</code> and <code>[2pm-3pm]</code>.</p>