Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bug with publishing form with conflicting version #1403

Open
ktuite opened this issue Feb 12, 2025 · 3 comments
Open

Bug with publishing form with conflicting version #1403

ktuite opened this issue Feb 12, 2025 · 3 comments
Labels

Comments

@ktuite
Copy link
Member

ktuite commented Feb 12, 2025

I was looking at something to do with form manifests containing entity lists, and in one of my tests, I got a really unexpected 500 error.

Below is the test. The very last line of trying to fetch the attachment (which should download the entity list) fails ONLY if a previous request to publish is sent that results in a 409. (This test might be longer than it needs to be for this issue... but I already pruned out some other unnecessary stuff.)

    it.only('should return return correct version of attachment (dataset) in manifest', testService(async (service) => {
      const asAlice = await service.login('alice');

      // Upload form with slot for attachment goodone.csv
      await asAlice.post('/v1/projects/1/forms')
        .send(testData.forms.withAttachments)
        .set('Content-Type', 'application/xml')
        .expect(200);

      // Upload attachment csv (not a dataset)
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft/attachments/goodone.csv')
        .send('test,csv\n1,2')
        .set('Content-Type', 'text/csv')
        .expect(200);

      // Publish form
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft/publish')
        .expect(200);

      // ---- Create a new draft of the form with different attachment to be linked to dataset ----
      // Create dataset called people
      await asAlice.post('/v1/projects/1/datasets')
        .send({ name: 'people' })
        .expect(200);

      // Create new draft: wont autolink because .CSV doesn't match .csv and autolinker is very strict
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft')
        .send(testData.forms.withAttachments
          .replace('goodone.csv', 'people.CSV'))
        .set('Content-Type', 'application/xml')
        .expect(200);

      // ----- Explicitly link attachment to dataset ----
      await asAlice.patch('/v1/projects/1/forms/withAttachments/draft/attachments/people.CSV')
        .send({ dataset: true })
        .expect(200);

      // I should be able to download the draft dataset attachment
      await asAlice.get('/v1/projects/1/forms/withAttachments/draft/attachments/people.CSV')
        .expect(200);

      // This should not be available until the form is published
      await asAlice.get('/v1/projects/1/forms/withAttachments/attachments/people.CSV')
        .expect(404);

      // Publish the form
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft/publish')
        .expect(409);
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft/publish?version=2')
        .expect(200);
      await asAlice.get('/v1/projects/1/forms/withAttachments/attachments/people.CSV')
        .then(({ body, text }) => {
          console.log(body, text);
        });
    }));

The offending part of the code seems to be here where we publish a form.
https://github.com/getodk/central-backend/blob/master/lib/model/query/forms.js#L336

Where we catch a uniqueness violation (and return it in the API response) but continue on with the rest of the function to try to autolink the dataset and to make a new Form def.

@alxndrsn
Copy link
Contributor

I think this may be an artefact of how integration tests use postgres transactions rather than an internal problem relating to form publishing.

This can be seen more clearly by modifying the test to:

    it.only('should return return correct version of attachment (dataset) in manifest', testService(async function(service) {
      this.timeout(20000);

      const asAlice = await service.login('alice');

      // Upload form with slot for attachment goodone.csv
      await asAlice.post('/v1/projects/1/forms')
        .send(testData.forms.withAttachments)
        .set('Content-Type', 'application/xml')
        .expect(200);

      // Upload attachment csv (not a dataset)
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft/attachments/goodone.csv')
        .send('test,csv\n1,2')
        .set('Content-Type', 'text/csv')
        .expect(200);

      // Publish form
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft/publish')
        .expect(200);

      // ---- Create a new draft of the form with different attachment to be linked to dataset ----
      // Create dataset called people
      await asAlice.post('/v1/projects/1/datasets')
        .send({ name: 'people' })
        .expect(200);

      // Create new draft: wont autolink because .CSV doesn't match .csv and autolinker is very strict
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft')
        .send(testData.forms.withAttachments
          .replace('goodone.csv', 'people.CSV'))
        .set('Content-Type', 'application/xml')
        .expect(200);

      // ----- Explicitly link attachment to dataset ----
      await asAlice.patch('/v1/projects/1/forms/withAttachments/draft/attachments/people.CSV')
        .send({ dataset: true })
        .expect(200);

      // I should be able to download the draft dataset attachment
      await asAlice.get('/v1/projects/1/forms/withAttachments/draft/attachments/people.CSV')
        .expect(200);

      // This should not be available until the form is published
      await asAlice.get('/v1/projects/1/forms/withAttachments/attachments/people.CSV')
        .expect(404);

      // Publish the form
      await asAlice.post('/v1/projects/1/forms/withAttachments/draft/publish')
        .expect(409);

      // !!! CHANGES FROM HERE ONWARDS !!! //

      console.log('=== Sleeping for 5 seconds to separate postgres logs ===');
      await new Promise(resolve => setTimeout(resolve, 5000));

      await asAlice.get('/v1/roles')
        .expect(200);
    }));

This test fails similarly:

  1) datasets and entities
       should return return correct version of attachment (dataset) in manifest:
     Error: expected 200 "OK", got 500 "Internal Server Error"
      at Context.<anonymous> (test/integration/api/datasets.js:74:10)
      at async Object.transaction (node_modules/slonik/dist/src/connectionMethods/transaction.js:22:24)
      at async Object.createConnection (node_modules/slonik/dist/src/factories/createConnection.js:97:18)
  ----
      at Test._assertStatus (node_modules/supertest/lib/test.js:252:14)
      at /home/user/workspaces/odk/backend/node_modules/supertest/lib/test.js:308:13
      at Test._assertFunction (node_modules/supertest/lib/test.js:285:13)
      at Test.assert (node_modules/supertest/lib/test.js:164:23)
      at Server.localAssert (node_modules/supertest/lib/test.js:120:14)
      at Object.onceWrapper (node:events:638:28)
      at Server.emit (node:events:524:28)
      at Server.emit (node:domain:489:12)
      at emitCloseNT (node:net:2383:8)
      at process.processTicksAndRejections (node:internal/process/task_queues:89:21)

Postgres logs:

2025-02-19 07:36:24.933 UTC [304] LOG:  execute <unnamed>: 
	update "form_defs"
	set "draftToken"=$1,"enketoId"=$2,"publishedAt"=$3
	
	where "id"=$4
	returning *
2025-02-19 07:36:24.933 UTC [304] DETAIL:  parameters: $1 = NULL, $2 = NULL, $3 = '2025-02-19 07:36:24.929+00', $4 = '4'
2025-02-19 07:36:24.934 UTC [304] ERROR:  ODK02:1:'withAttachments':''
2025-02-19 07:36:24.934 UTC [304] CONTEXT:  PL/pgSQL function check_form_version() line 16 at RAISE
2025-02-19 07:36:24.934 UTC [304] STATEMENT:  
	update "form_defs"
	set "draftToken"=$1,"enketoId"=$2,"publishedAt"=$3
	
	where "id"=$4
	returning *
2025-02-19 07:36:29.951 UTC [304] ERROR:  current transaction is aborted, commands ignored until end of transaction block
2025-02-19 07:36:29.951 UTC [304] STATEMENT:  
	select "sessions"."actorId" as "sessions!actorId","sessions"."token" as "sessions!token","sessions"."csrf" as "sessions!csrf","sessions"."expiresAt" as "sessions!expiresAt","sessions"."createdAt" as "sessions!createdAt","actors"."id" as "actors!id","actors"."type" as "actors!type","actors"."acteeId" as "actors!acteeId","actors"."displayName" as "actors!displayName","actors"."meta" as "actors!meta","actors"."createdAt" as "actors!createdAt","actors"."updatedAt" as "actors!updatedAt","actors"."deletedAt" as "actors!deletedAt" from sessions
	join actors on actors.id=sessions."actorId"
	where token=$1 and sessions."expiresAt" > now()
2025-02-19 07:36:29.960 UTC [304] LOG:  statement: rollback
2025-02-19 07:36:29.968 UTC [304] LOG:  statement: COMMIT
2025-02-19 07:36:29.968 UTC [304] WARNING:  there is no transaction in progress

@alxndrsn
Copy link
Contributor

I think the test can be simplified to:

it.only('should return return correct version of attachment (dataset) in manifest', testService(async function(service) {
  this.timeout(20000);

  const asAlice = await service.login('alice');

  // Upload form with slot for attachment goodone.csv
  await asAlice.post('/v1/projects/1/forms')
    .send(testData.forms.simpleEntity)
    .set('Content-Type', 'application/xml')
    .expect(200);

  // Publish form
  await asAlice.post('/v1/projects/1/forms/simpleEntity/draft/publish')
    .expect(200);

  // Create new draft
  await asAlice.post('/v1/projects/1/forms/simpleEntity/draft')
    .send(testData.forms.simpleEntity)
    .set('Content-Type', 'application/xml')
    .expect(200);

  // Publish the form
  await asAlice.post('/v1/projects/1/forms/simpleEntity/draft/publish')
    .expect(409);

  console.log('=== Sleeping for 5 seconds to separate postgres logs ===');
  await new Promise(resolve => setTimeout(resolve, 5000));

  await asAlice.get('/v1/roles')throw
    .expect(200);
}));

Testing this request flow against a real server does not seem to demonstrate the same issue - subsequent calls to /publish will repeatedly return 409 without issue.

@alxndrsn
Copy link
Contributor

I think this may be an artefact of how integration tests use postgres transactions rather than an internal problem relating to form publishing.

More support for this: changing testService() to testServiceFullTrx() makes the test pass.

It would be more intuitive if integration tests were not processing separate HTTP requests within the same database transaction.

alxndrsn pushed a commit to alxndrsn/odk-central-backend that referenced this issue Feb 19, 2025
Follow-up to getodk#1402
Noticed while investigating getodk#1403

Due to use of `function()` in the test wrappers, `this` was unbound from the real test functions.  This PR re-binds mocha's `this` to the test functions, allowing use of e.g. `this.timeout(...)` in individual tests.
alxndrsn pushed a commit to alxndrsn/odk-central-backend that referenced this issue Feb 19, 2025
Noted while investigating getodk#1403

Some logging is not followed by a newline character, so it is concatenated with the next output to stderrr.

This commit adds newline characters to calls to process.stderr.write() where missing, and standardises their inclusion.

It's unclear why `process.stderr.write()` is used in preference to `console.error()`
alxndrsn added a commit that referenced this issue Feb 20, 2025
Noted while investigating #1403.

Some logging is not followed by a newline character, so it is concatenated with the next output to `stderrr`.

This commit adds newline characters to calls to `process.stderr.write()` where missing, and standardises their inclusion.

It's unclear why `process.stderr.write()` is used in preference to `console.error()` - see #1416.

Co-authored-by: alxndrsn <alxndrsn>
alxndrsn added a commit that referenced this issue Feb 20, 2025
Follow-up to #1402
Noticed while investigating #1403

Due to use of `function()` in the test wrappers, `this` was unbound from the real test functions.  This PR re-binds mocha's `this` to the test functions, allowing use of e.g. `this.timeout(...)` in individual tests.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
Status: 🕒 backlog
Development

No branches or pull requests

2 participants