ASP .NET WebMethods Synchronization

ASP .NET WebMethods Synchronization

I have a webmethod in asp.net .asmx service, wich is supposed to check if
there are records in a DB, and if there are no records it should add a
record
the simplified example of code is like this:
object Mutex = new object();
[WebMethod]
public void InsertIfNotExists(string CLI)
{
lock (Mutex)
{
using (SqlConnection conn = new SqlConnection(ConnectionString))
using (SqlDataAdapter adapter = new SqlDataAdapter())
using (DataSet ds = new System.Data.DataSet()){
{
//I log with log4net
logger.Debug("InsertIfNotExists: Start Function: CLI:" + CLI);
int dummy = 0;
string sql = "SELECT * CLI Promote where CLI=" + CLI + " ";
adapter.SelectCommand = new SqlCommand(sql, conn);
adapter.Fill(ds);
DataTable t = ds.Tables[0];
logger.Debug("InsertIfNotExists: " + t.Rows.Count + " records
found for CLI:" + CLI);
if (t.Rows.Count == 0)
{
logger.Debug("InsertIfNotExists: starting to add to table:
CLI:" + CLI);
DataRow dr = t.NewRow();
dr["CLI"] = CLI;
dr["DateOfSend"] = DateTime.Now;
InsertToTable(t, dr, sql);
logger.Debug("InsertIfNotExists: added to table: CLI:" + CLI +
", starting re-check");
//checking if exist more then one lines - one more time
sql = "SELECT * CLI Promote where CLI=" + CLI + "";
adapter.SelectCommand = new SqlCommand(sql, conn);
adapter.Fill(ds);
t = ds.Tables[0];
logger.Debug("InsertIfNotExists: re-check for CLI:" + CLI + ",
records count=" + t.Rows.Count);
}
logger.Debug("InsertIfNotExists: Finish Function for CLI:" + CLI);
}
}
}
Actually it does more checks and logic, that's why I implement it in .net
and not in the SQL statement itself, but essentially that is it.
Most of the time the code works well, but sometimes I get into race
conditions because of multithreading, though I use lock.
Sample output I got today:
2013-09-15 11:47:14,145 [21] DEBUG Namespace.Service1 InsertIfNotExists:
Start Function: CLI: 0501234567
2013-09-15 11:47:14,145 [13] DEBUG Namespace.Service1 InsertIfNotExists:
Start Function: CLI: 0501234567
2013-09-15 11:47:14,148 [21] DEBUG Namespace.Service1 InsertIfNotExists: 0
records found for CLI: 0501234567
2013-09-15 11:47:14,148 [21] DEBUG Namespace.Service1 InsertIfNotExists:
starting to add to table: CLI: 0501234567
2013-09-15 11:47:14,148 [13] DEBUG Namespace.Service1 InsertIfNotExists: 0
records found for CLI: 0501234567
2013-09-15 11:47:14,148 [13] DEBUG Namespace.Service1 InsertIfNotExists:
starting to add to table: CLI: 0501234567
2013-09-15 11:47:14,149 [21] DEBUG Namespace.Service1 InsertIfNotExists:
added to table: CLI: 0501234567, starting re-check
2013-09-15 11:47:14,149 [13] DEBUG Namespace.Service1 InsertIfNotExists:
added to table: CLI: 0501234567, starting re-check
2013-09-15 11:47:14,154 [27] DEBUG Namespace.Service1 InsertIfNotExists:
Start Function: CLI: 0501234567
2013-09-15 11:47:14,157 [27] DEBUG Namespace.Service1 InsertIfNotExists: 2
records found for CLI: 0501234567
2013-09-15 11:47:14,157 [27] DEBUG Namespace.Service1 InsertIfNotExists:
Finish Function for CLI: 0501234567
2013-09-15 11:47:14,183 [13] DEBUG Namespace.Service1 InsertIfNotExists:
re-check for CLI: 0501234567, records count=2
2013-09-15 11:47:14,184 [21] DEBUG Namespace.Service1 InsertIfNotExists:
re-check for CLI: 0501234567, records count=2
2013-09-15 11:47:14,185 [13] DEBUG Namespace.Service1 InsertIfNotExists:
Finish Function for CLI: 0501234567
2013-09-15 11:49:19,626 [21] DEBUG Namespace.Service1 InsertIfNotExists:
Start Function: CLI:0507654321
What we see here that 3 threads attempted to insert CLI 0501234567 to the
table in the parallel. Threads 21 and 13 entered the race conditons and
each one inserted 1 record. Then thread 27 also tried to insert a record,
but found existing records and exited.
Why did they do it when locked on mutex?
Additional strange thing is that the thread 21 did never got to the line
logger.Debug("InsertIfNotExists: Finish Function for CLI:" + CLI);
and somehow jumped to starting the function from the beginning for another
CLI.
2013-09-15 11:49:19,626 [21] DEBUG Namespace.Service1 InsertIfNotExists:
Start Function: CLI:0507654321
Why does asp.net behave in such a way and what is the proper thing to
accomplishing that task without the race conditions?