Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 362763

Summary: Request to write data into a file failed on Linux.
Product: [Tools] TCF Reporter: William Chen <william.chen>
Component: TargetAssignee: Project Inbox <tcf.tm-inbox>
Status: RESOLVED FIXED QA Contact: Uwe Stieber <uwe.st>
Severity: normal    
Priority: P3 CC: cdtdoug, eugene, mober.at+eclipse, uwe.st, william.chen
Version: unspecified   
Target Milestone: 1.0.0   
Hardware: PC   
OS: Linux   
Whiteboard:
Attachments:
Description Flags
test case
none
Revised testcase. none

Description William Chen CLA 2011-11-03 03:31:40 EDT 
Build Identifier: 

The agent was running on Linux as the root. I created an empty file named "x.txt" using my own account and granted the root write permission:

-rw-rw-rw-  1 wchen users      0 2011-11-03 15:02 x.txt

Then I opened this file and edited it in Target Explorer. I entered a line "Hello, world!" into this file and saved it. Upon saving, Target Explorer should have updated "x.txt" with the content "Hello, world!". However, when I opened "x.txt" using vi on this Linux host, this file was still empty!

I collected the logs generated by tcflog and found the following lines:

TCF 08:42.150: 110: ---> C 42 FileSystem open "/folk/wchen/x.txt" 2 null <eom>
TCF 08:42.151: 110: <--- R 42  "FS14" <eom>
TCF 08:42.154: 110: ---> C 43 FileSystem write "FS14" 0 (13)Hello,\x20world! <eom>
TCF 08:42.154: 110: <--- R 43  <eom>
TCF 08:42.156: 110: ---> C 44 FileSystem close "FS14" <eom>
TCF 08:42.156: 110: <--- R 44  <eom>

It is clear that the front end did send the command requesting for writing "Hello, world!" into the file "x.txt". However somehow the agent failed to write the data into the file.



Reproducible: Always

Steps to Reproduce:

1.Run the agent on a Linux host as a root. Run tcflog in parallel with the agent  to collect the logs.
2.Create an empty file using a normal user account.
3.Grant the root the write permission to this file.
4.Open the Target Explorer view in eclipse, you should have seen the two TCF agents in the view.
5.Select the tcflog and open its properties editor. Switch to its "File System" tab and expand the file system tree to the file.
6.Open the file in an editor and enter some data into the editor.
7.Save the file.
8.Check the content of the file using vi on the linux host. You'll see it is still empty.
9.Check the logs generated by tcflog. You'll find the above logs indicating that the command for writing the data has been received by the agent, while the agent fails to update the file's content.
Comment 1 Eugene Tarassov CLA 2011-11-03 18:26:33 EDT 
Created attachment 206436 [details]
test case
Comment 2 Eugene Tarassov CLA 2011-11-03 18:27:26 EDT 
I cannot reproduce it. 
I have created a test case - attached.
It works fine.
Comment 3 William Chen CLA 2011-11-04 01:27:15 EDT 
This is very weird. I used you testcase and it worked. But target explorer simply couldn't work. Could you please follow the steps to reproduce I mentioned to reproduce it?
Comment 4 William Chen CLA 2011-11-04 03:25:48 EDT 
Created attachment 206446 [details]
Revised testcase.

Hi Eugene,

I revised your test case a little bit so that we could pass a command line argument as the data to be written. Then I ran it twice:

java Main "Hello, world!"
java Main "xxxxx"

Then I opened the file using vi and found the following content:

xxxxx, world!

I think there must be something with the agent. Please try the attached test case with the above steps.
Comment 5 Eugene Tarassov CLA 2011-11-04 12:21:50 EDT 
(In reply to comment #4)
> Created attachment 206446 [details]
> Revised testcase.
> 
> Hi Eugene,
> 
> I revised your test case a little bit so that we could pass a command line
> argument as the data to be written. Then I ran it twice:
> 
> java Main "Hello, world!"
> java Main "xxxxx"
> 
> Then I opened the file using vi and found the following content:
> 
> xxxxx, world!
> 
> I think there must be something with the agent. Please try the attached test
> case with the above steps.

This is correct behavior. If you want the file truncated, you need to open it with 
 TCF_O_TRUNC flag.
Comment 6 Uwe Stieber CLA 2011-11-04 12:54:32 EDT 
The log from the description below shows that the client is sending the write command. Still the result is that the content does not make it to the file on the remote side. What could be the explanation for it? Probably closing the file descriptor to early? The write command appears to return immediately. The time stamp of the command and the response are identical (knowing that the time stamps are not real time). Is there any kind of tracing we can enable on the agent side?
Comment 7 Eugene Tarassov CLA 2011-11-04 14:58:11 EDT 
(In reply to comment #6)
> The log from the description below shows that the client is sending the write
> command. 

Yes, the log looks fine.

> Still the result is that the content does not make it to the file on
> the remote side. What could be the explanation for it?

I have no idea.

> Probably closing the
> file descriptor to early?

It is OK to send close command right after write command, even before it reply. The agent will serialize file access as necessary. But, according to the log, it is not the case anyway.

> The write command appears to return immediately. The
> time stamp of the command and the response are identical (knowing that the time
> stamps are not real time). Is there any kind of tracing we can enable on the
> agent side?

You can try -l0x120 option.
It should produce output like this (type 3 = write, type 13 = close):

TCF 33:02.283: Starting channel 0x11b02f0 TCP:172.25.38.197:1268
TCF 33:02.283: channel server connecting
TCF 33:02.283: async_req_post: req 0x11b16c0, type 4
TCF 33:02.283: async_req_post: req 0x11adea8, type 8
TCF 33:02.283: async_req_post: req 0x11b1500, type 5
TCF 33:02.283: async_req_complete: req 0x11b1500, type 5, error 0
TCF 33:02.305: async_req_complete: req 0x11b16c0, type 4, error 0
TCF 33:02.305: async_req_post: req 0x11b16c0, type 4
TCF 33:02.305: Peer TCP:172.25.38.197:1268: Event: E Locator Hello ...
TCF 33:02.305: channel server connected, remote services:
TCF 33:02.305:   Diagnostics
TCF 33:02.305:   Locator
TCF 33:02.305:   ZeroCopy
TCF 33:02.379: async_req_complete: req 0x11b16c0, type 4, error 0
TCF 33:02.379: async_req_post: req 0x11b16c0, type 4
TCF 33:02.379: Peer TCP:172.25.38.197:1268: Command: C 0 FileSystem open ...
TCF 33:02.380: async_req_post: req 0x11b1500, type 5
TCF 33:02.380: async_req_complete: req 0x11b1500, type 5, error 0
TCF 33:02.417: async_req_complete: req 0x11b16c0, type 4, error 0
TCF 33:02.417: async_req_post: req 0x11b16c0, type 4
TCF 33:02.417: Peer TCP:172.25.38.197:1268: Command: C 1 FileSystem write ...
TCF 33:02.417: async_req_post: req 0x11b8e70, type 3
TCF 33:02.417: async_req_complete: req 0x11b8e70, type 3, error 0
TCF 33:02.417: async_req_post: req 0x11b1500, type 5
TCF 33:02.417: async_req_complete: req 0x11b1500, type 5, error 0
TCF 33:02.444: async_req_complete: req 0x11b16c0, type 4, error 0
TCF 33:02.444: async_req_post: req 0x11b16c0, type 4
TCF 33:02.444: Peer TCP:172.25.38.197:1268: Command: C 2 FileSystem close ...
TCF 33:02.444: async_req_post: req 0x11b8e70, type 13
TCF 33:02.444: async_req_complete: req 0x11b8e70, type 13, error 0
TCF 33:02.444: async_req_post: req 0x11b1500, type 5
TCF 33:02.444: async_req_complete: req 0x11b1500, type 5, error 0
TCF 33:02.470: async_req_complete: req 0x11b16c0, type 4, error 0
TCF 33:02.471: Socket is shutdown by remote peer, channel 0x11b02f0 TCP:172.25.38.197:1268
TCF 33:02.471: Closing channel 0x11b02f0 TCP:172.25.38.197:1268
Comment 8 Uwe Stieber CLA 2011-11-17 08:30:48 EST 
Hi Eugene,

You had been absolutely right, the issue had been within the client. And as you hinted in comment #5, the flags given to the open(...) call had been wrong. I've changed the flags used from "TCF_O_WRITE" to "TCF_O_WRITE | TCF_O_CREAT | TCF_O_TRUNC". I'm not longer able to reproduce the issue than.

Moving the bug to the "Target" component and closing it.

Thanks for the help!