{"action":"created","issue":{"url":"https://api.github.com/repos/npgsql/npgsql/issues/1454","repository_url":"https://api.github.com/repos/npgsql/npgsql","labels_url":"https://api.github.com/repos/npgsql/npgsql/issues/1454/labels{/name}","comments_url":"https://api.github.com/repos/npgsql/npgsql/issues/1454/comments","events_url":"https://api.github.com/repos/npgsql/npgsql/issues/1454/events","html_url":"https://github.com/npgsql/npgsql/issues/1454","id":209386460,"number":1454,"title":"Npgsql.NpgsqlOperationInProgressException using Datareader","user":{"login":"kcwitt","id":2939651,"avatar_url":"https://avatars0.githubusercontent.com/u/2939651?v=3","gravatar_id":"","url":"https://api.github.com/users/kcwitt","html_url":"https://github.com/kcwitt","followers_url":"https://api.github.com/users/kcwitt/followers","following_url":"https://api.github.com/users/kcwitt/following{/other_user}","gists_url":"https://api.github.com/users/kcwitt/gists{/gist_id}","starred_url":"https://api.github.com/users/kcwitt/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kcwitt/subscriptions","organizations_url":"https://api.github.com/users/kcwitt/orgs","repos_url":"https://api.github.com/users/kcwitt/repos","events_url":"https://api.github.com/users/kcwitt/events{/privacy}","received_events_url":"https://api.github.com/users/kcwitt/received_events","type":"User","site_admin":false},"labels":[{"id":69978383,"url":"https://api.github.com/repos/npgsql/npgsql/labels/bug","name":"bug","color":"e11d21","default":true}],"state":"open","locked":false,"assignee":{"login":"Emill","id":1660778,"avatar_url":"https://avatars2.githubusercontent.com/u/1660778?v=3","gravatar_id":"","url":"https://api.github.com/users/Emill","html_url":"https://github.com/Emill","followers_url":"https://api.github.com/users/Emill/followers","following_url":"https://api.github.com/users/Emill/following{/other_user}","gists_url":"https://api.github.com/users/Emill/gists{/gist_id}","starred_url":"https://api.github.com/users/Emill/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Emill/subscriptions","organizations_url":"https://api.github.com/users/Emill/orgs","repos_url":"https://api.github.com/users/Emill/repos","events_url":"https://api.github.com/users/Emill/events{/privacy}","received_events_url":"https://api.github.com/users/Emill/received_events","type":"User","site_admin":false},"assignees":[{"login":"Emill","id":1660778,"avatar_url":"https://avatars2.githubusercontent.com/u/1660778?v=3","gravatar_id":"","url":"https://api.github.com/users/Emill","html_url":"https://github.com/Emill","followers_url":"https://api.github.com/users/Emill/followers","following_url":"https://api.github.com/users/Emill/following{/other_user}","gists_url":"https://api.github.com/users/Emill/gists{/gist_id}","starred_url":"https://api.github.com/users/Emill/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Emill/subscriptions","organizations_url":"https://api.github.com/users/Emill/orgs","repos_url":"https://api.github.com/users/Emill/repos","events_url":"https://api.github.com/users/Emill/events{/privacy}","received_events_url":"https://api.github.com/users/Emill/received_events","type":"User","site_admin":false}],"milestone":{"url":"https://api.github.com/repos/npgsql/npgsql/milestones/41","html_url":"https://github.com/npgsql/npgsql/milestone/41","labels_url":"https://api.github.com/repos/npgsql/npgsql/milestones/41/labels","id":2322167,"number":41,"title":"3.2.2","description":"","creator":{"login":"roji","id":1862641,"avatar_url":"https://avatars3.githubusercontent.com/u/1862641?v=3","gravatar_id":"","url":"https://api.github.com/users/roji","html_url":"https://github.com/roji","followers_url":"https://api.github.com/users/roji/followers","following_url":"https://api.github.com/users/roji/following{/other_user}","gists_url":"https://api.github.com/users/roji/gists{/gist_id}","starred_url":"https://api.github.com/users/roji/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/roji/subscriptions","organizations_url":"https://api.github.com/users/roji/orgs","repos_url":"https://api.github.com/users/roji/repos","events_url":"https://api.github.com/users/roji/events{/privacy}","received_events_url":"https://api.github.com/users/roji/received_events","type":"User","site_admin":false},"open_issues":4,"closed_issues":7,"state":"open","created_at":"2017-02-14T16:14:36Z","updated_at":"2017-03-01T18:18:56Z","due_on":null,"closed_at":null},"comments":8,"created_at":"2017-02-22T08:41:37Z","updated_at":"2017-03-01T19:49:23Z","closed_at":null,"body":"When using a datareader in an Async function, an exception is thrown when closing the datareader with Npgsql 3.2.1.\r\n\r\nThe following test function shows this. It connects to the database, and queries a single column from one of the built-in PostgreSQL catalog tables.\r\n\r\nMost of this function is connection string initialization and debugging comments to produce the output at the end of this message. The database is running on the local machine, so there should not be any networking issues.\r\n\r\n```\r\nPublic Async Function NpgsqlExceptionExample(userInfo As VSLicenseManager.UserInfo) As Threading.Tasks.Task\r\n\tTry\r\n\t\tDebug.WriteLine(\"Creating Connection\")\r\n\t\tDim connectionString As String = Nothing\r\n\t\tWith New Npgsql.NpgsqlConnectionStringBuilder\r\n\t\t\t.Username = userInfo.UserName\r\n\t\t\t.Password = userInfo.Password\r\n\t\t\t.Host = userInfo.DBServer\r\n\t\t\t.Database = userInfo.Database\r\n\t\t\t.Port = userInfo.Port\r\n\t\t\t.ApplicationName = userInfo.License.Application\r\n\t\t\t.SslMode = Npgsql.SslMode.Require\r\n\t\t\tconnectionString = .ConnectionString\r\n\t\tEnd With\r\n\t\tUsing conn As New Npgsql.NpgsqlConnection(connectionString) With {\r\n\t\t\t.ProvideClientCertificatesCallback = AddressOf userInfo.ProvideClientCertificatesCallback,\r\n\t\t\t.UserCertificateValidationCallback = AddressOf userInfo.RemoteCertificateValidationCallback\r\n\t\t\t}\r\n\t\t\tDebug.WriteLine(\"Opening Connection\")\r\n\t\t\tAwait conn.OpenAsync.ConfigureAwait(False)\r\n\t\t\tDebug.WriteLine(\"Begining Transaction\")\r\n\t\t\tUsing trans As Npgsql.NpgsqlTransaction = conn.BeginTransaction\r\n\t\t\t\tDim command As Npgsql.NpgsqlCommand = conn.CreateCommand\r\n\t\t\t\tcommand.CommandText = \"SELECT relname FROM pg_class;\"\r\n\t\t\t\tDebug.WriteLine(\"Executing Datareader\")\r\n\t\t\t\tDim i = 0\r\n\t\t\t\tUsing dr As Npgsql.NpgsqlDataReader = Await command.ExecuteReaderAsync.ConfigureAwait(False)\r\n\t\t\t\t\tWhile Await dr.ReadAsync.ConfigureAwait(False)\r\n\t\t\t\t\t\tDim example = dr(0)\r\n\t\t\t\t\t\ti += 1\r\n\t\t\t\t\tEnd While\r\n\t\t\t\t\tDebug.WriteLine(String.Format(\"Iterated {0:#,##0} records\", i))\r\n\t\t\t\t\tDebug.WriteLine(\"Disposing Datareader\")\r\n\t\t\t\tEnd Using\r\n\t\t\t\tDebug.WriteLine(\"Disposing Transaction\")\r\n\t\t\tEnd Using\r\n\t\t\tDebug.WriteLine(\"Disposing Connection\")\r\n\t\tEnd Using\r\n\tCatch ex As Exception\r\n\t\tDebug.WriteLine(String.Format(\"Tossme Function Error: {0}\", ex.Message))\r\n\tEnd Try\r\nEnd Function\r\n```\r\n\r\nThis function is called like:\r\n```\r\nFor i = 0 To 100\r\n\tDebug.WriteLine(String.Format(\"Begining cycle {0:#,##0}\", i))\r\n\tNpgsqlExceptionExample(login.SelectedLicense.DefaultUserInfo).Wait()\r\n\tDebug.WriteLine(String.Format(\"Finished cycle {0:#,##0}\", i))\r\nNext\r\n```\r\n\r\nThe output from the first five iterations from the debug console (with Npgsql logging turned on) is as follows. The exception seems to occur randomly; in this case it occurs in cycle 0, and then the next several cycles run okay, and then it occurs again in cycle 7. In my case, there are 938 records in that table, so it seems to work okay up until the disposals start.\r\n\r\n> Begining cycle 0\r\n> Creating Connection\r\n> Opening Connection\r\n> Begining Transaction\r\n> Executing Datareader\r\n> dbug: Npgsql[3]\r\n>       [16405] Connection opened\r\n> dbug: Npgsql[300]\r\n>       [16405] Beginning transaction with isolation level Unspecified\r\n> dbug: Npgsql[100]\r\n>       [16405] Executing statement(s):\r\n>       \tSELECT relname FROM pg_class\r\n> Iterated 938 records\r\n> Disposing Datareader\r\n> Disposing Transaction\r\n> Exception thrown: 'System.IO.IOException' in Npgsql.dll\r\n> dbug: Npgsql[302]\r\n>       [16405] Rolling back transaction\r\n> Exception thrown: 'System.IO.IOException' in mscorlib.dll\r\n> Exception thrown: 'Npgsql.NpgsqlException' in Npgsql.dll\r\n> Exception thrown: 'Npgsql.NpgsqlException' in mscorlib.dll\r\n> Exception thrown: 'Npgsql.NpgsqlException' in mscorlib.dll\r\n> Exception thrown: 'Npgsql.NpgsqlException' in mscorlib.dll\r\n> fail: Npgsql[14]\r\n>       [16405] Breaking connector\r\n> dbug: Npgsql[5]\r\n>       [16405] Connection closed\r\n> ---- Tossme Function Error: Exception while writing to stream\r\n> ----     Inner Exception is: Cannot write data until everything buffered has been read\r\n> Finished cycle 0\r\n> Begining cycle 1\r\n> Creating Connection\r\n> Opening Connection\r\n> Begining Transaction\r\n> Executing Datareader\r\n> dbug: Npgsql[3]\r\n>       [16406] Connection opened\r\n> dbug: Npgsql[300]\r\n>       [16406] Beginning transaction with isolation level Unspecified\r\n> dbug: Npgsql[100]\r\n>       [16406] Executing statement(s):\r\n>       \tSELECT relname FROM pg_class\r\n> Iterated 938 records\r\n> Disposing Datareader\r\n> Disposing Transaction\r\n> Disposing Connection\r\n> Finished cycle 1\r\n> Begining cycle 2\r\n> Creating Connection\r\n> Opening Connection\r\n> Begining Transaction\r\n> Executing Datareader\r\n> dbug: Npgsql[302]\r\n>       [16406] Rolling back transaction\r\n> dbug: Npgsql[5]\r\n>       [16406] Connection closed\r\n> dbug: Npgsql[3]\r\n>       [16406] Connection opened\r\n> dbug: Npgsql[300]\r\n>       [16406] Beginning transaction with isolation level Unspecified\r\n> dbug: Npgsql[100]\r\n>       [16406] Executing statement(s):\r\n>       \tSELECT relname FROM pg_class\r\n> Iterated 938 records\r\n> Disposing Datareader\r\n> Disposing Transaction\r\n> Disposing Connection\r\n> Finished cycle 2\r\n> Begining cycle 3\r\n> Creating Connection\r\n> Opening Connection\r\n> Begining Transaction\r\n> Executing Datareader\r\n> Iterated 938 records\r\n> Disposing Datareader\r\n> Disposing Transaction\r\n> Disposing Connection\r\n> Finished cycle 3\r\n> Begining cycle 4\r\n> Creating Connection\r\n> Opening Connection\r\n> Begining Transaction\r\n> Executing Datareader\r\n> dbug: Npgsql[302]\r\n>       [16406] Rolling back transaction\r\n> dbug: Npgsql[5]\r\n>       [16406] Connection closed\r\n> dbug: Npgsql[3]\r\n>       [16406] Connection opened\r\n> dbug: Npgsql[300]\r\n>       [16406] Beginning transaction with isolation level Unspecified\r\n> dbug: Npgsql[100]\r\n>       [16406] Executing statement(s):\r\n>       \tSELECT relname FROM pg_class\r\n> dbug: Npgsql[302]\r\n>       [16406] Rolling back transaction\r\n> dbug: Npgsql[5]\r\n>       [16406] Connection closed\r\n> dbug: Npgsql[3]\r\n>       [16406] Connection opened\r\n> dbug: Npgsql[300]\r\n>       [16406] Beginning transaction with isolation level Unspecified\r\n> dbug: Npgsql[100]\r\n>       [16406] Executing statement(s):\r\n>       \tSELECT relname FROM pg_class\r\n> Iterated 938 records\r\n> Disposing Datareader\r\n> Disposing Transaction\r\n> Disposing Connection\r\n> Finished cycle 4\r\n> Begining cycle 5\r\n> Creating Connection\r\n> Opening Connection\r\n> Begining Transaction\r\n> Executing Datareader\r\n> dbug: Npgsql[302]\r\n>       [16406] Rolling back transaction\r\n> dbug: Npgsql[5]\r\n>       [16406] Connection closed\r\n> dbug: Npgsql[3]\r\n>       [16406] Connection opened\r\n> dbug: Npgsql[300]\r\n>       [16406] Beginning transaction with isolation level Unspecified\r\n> dbug: Npgsql[100]\r\n>       [16406] Executing statement(s):\r\n>       \tSELECT relname FROM pg_class\r\n> Iterated 938 records\r\n> Disposing Datareader\r\n> Disposing Transaction\r\n> Disposing Connection\r\n> Finished cycle 5\r\n> Begining cycle 6\r\n> Creating Connection\r\n> Opening Connection\r\n> Begining Transaction\r\n> Executing Datareader\r\n> Iterated 938 records\r\n> Disposing Datareader\r\n> Disposing Transaction\r\n> Disposing Connection\r\n> Finished cycle 6\r\n> Begining cycle 7\r\n> Creating Connection\r\n> Opening Connection\r\n> Begining Transaction\r\n> dbug: Npgsql[302]\r\n>       [16406] Rolling back transaction\r\n> dbug: Npgsql[5]\r\n>       [16406] Connection closed\r\n> dbug: Npgsql[3]\r\n>       [16406] Connection opened\r\n> dbug: Npgsql[300]\r\n>       [16406] Beginning transaction with isolation level Unspecified\r\n> dbug: Npgsql[100]\r\n>       [16406] Executing statement(s):\r\n>       \tSELECT relname FROM pg_class\r\n> dbug: Npgsql[302]\r\n>       [16406] Rolling back transaction\r\n> dbug: Npgsql[5]\r\n>       [16406] Connection closed\r\n> dbug: Npgsql[3]\r\n>       [16406] Connection opened\r\n> dbug: Npgsql[300]\r\n>       [16406] Beginning transaction with isolation level Unspecified\r\n> Executing Datareader\r\n> Iterated 938 records\r\n> Disposing Datareader\r\n> Disposing Transaction\r\n> Exception thrown: 'System.IO.IOException' in Npgsql.dll\r\n> Exception thrown: 'System.IO.IOException' in mscorlib.dll\r\n> Exception thrown: 'Npgsql.NpgsqlException' in Npgsql.dll\r\n> dbug: Npgsql[100]\r\n>       [16406] Executing statement(s):\r\n>       \tSELECT relname FROM pg_class\r\n> dbug: Npgsql[302]\r\n>       [16406] Rolling back transaction\r\n> fail: Npgsql[14]\r\n>       [16406] Breaking connector\r\n> dbug: Npgsql[5]\r\n>       [16406] Connection closed\r\n> Exception thrown: 'Npgsql.NpgsqlException' in mscorlib.dll\r\n> Exception thrown: 'Npgsql.NpgsqlException' in mscorlib.dll\r\n> Exception thrown: 'Npgsql.NpgsqlException' in mscorlib.dll\r\n> ---- Tossme Function Error: Exception while writing to stream\r\n> ----     Inner Exception is: Cannot write data until everything buffered has been read\r\n> Finished cycle 7\r\n"},"comment":{"url":"https://api.github.com/repos/npgsql/npgsql/issues/comments/283449343","html_url":"https://github.com/npgsql/npgsql/issues/1454#issuecomment-283449343","issue_url":"https://api.github.com/repos/npgsql/npgsql/issues/1454","id":283449343,"user":{"login":"roji","id":1862641,"avatar_url":"https://avatars3.githubusercontent.com/u/1862641?v=3","gravatar_id":"","url":"https://api.github.com/users/roji","html_url":"https://github.com/roji","followers_url":"https://api.github.com/users/roji/followers","following_url":"https://api.github.com/users/roji/following{/other_user}","gists_url":"https://api.github.com/users/roji/gists{/gist_id}","starred_url":"https://api.github.com/users/roji/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/roji/subscriptions","organizations_url":"https://api.github.com/users/roji/orgs","repos_url":"https://api.github.com/users/roji/repos","events_url":"https://api.github.com/users/roji/events{/privacy}","received_events_url":"https://api.github.com/users/roji/received_events","type":"User","site_admin":false},"created_at":"2017-03-01T19:49:23Z","updated_at":"2017-03-01T19:49:23Z","body":"It's curious, because the parallel read/write isn't new - 3.1 did the same but we never got complaints..."}}
{"actor":{"display_login":"roji"}}