Issue #75 resolved

Processing mercurial non-critical error messages

Anonymous created an issue

Sometimes when executing a mercurial command-line command it prints non-critical error message, for example "failed to import extension".

When executing the same command using Hgscc plugin Visual Studio show "Arithmetic operation resulted in an overflow." message window. This message is useless and hides original problem.

The enhancement is to display message box that will look like this: {{{ Operation executed successfully, but mercurial reports some problems: failed to import extension fold: No module named fold }}}

Comments (22)

  1. Sergey Antonov repo owner

    I'm trying to reproduce this issue, but it seems to work for me.

    I've enabled fold extension in mercurial.ini:

    [extensions]
    fold =
    

    After that I've checked, that it shows that message in console output:

    d:\Work\Mercurial\SccTests2\1\11>hg init
    *** failed to import extension fold: No module named fold
    
    d:\Work\Mercurial\SccTests2\1\11>echo a > a.txt
    
    d:\Work\Mercurial\SccTests2\1\11>hg add a.txt
    *** failed to import extension fold: No module named fold
    
    d:\Work\Mercurial\SccTests2\1\11>hg st
    *** failed to import extension fold: No module named fold
    A a.txt
    

    Now, I've tried to do the steps from your original issue using HgSccPackage in the IDE:

    1. Run the MS Visual Studio
    2. Create new C# Console Application project (File -> New -> Project -> Visual C# -> Console Application). Please use a path for a project that is not related to any of the existing mercurial repositories or subrepositories.
    3. Select solution file in the solution explorer
    4. Run "Add to source control" mercurial command from context menu or toolbar

    This is working fine for me. The project is added without an error.

    It seems that 'Arithmetic overflow' error may happen if the mercurial or some of its extensions violates a 'Command Server Protocol'.

    The command server protocol is working over redirected standard input/output pipes from the mercurial client process (see http://mercurial.selenic.com/wiki/CommandServer for details).

    If some of the extension simply write to the standard output ignoring the command server protocol, then it will break with arithmetic overflow error.

    So, without knowing which of the extension is causing that error it is not possible to fix it. Can you check again which of the extensions is causing that error ?

  2. Pavel Kolotey

    I have this issue on other PC with 32-bit win7.

    After I commented all extensions in mercurial.ini file all will work fine. Then I add 'abcde =' line and arithmetic overflow error happens. So, error happens if no extesion is enabled.

    Do you use tortoisehg-2.3.1-hg-2.1.1 distributive? Maybe something in this distributive causes the issue.

  3. Sergey Antonov repo owner

    Yes, I'm using a tortoisehg 2.3.1 with mercurial 2.1.1.

    I've checked a several PCs to reproduce this issue, but without a luck:

    • MS Windows Vista x86, MSVS 2008
    • MS Windows 8 Consumer Preview x64, MSVS 2008 and 2010

    I will try to get a clean environment with a virtual machines later on the week.

    Can you try the following in the command line and post an output here? Maybe it will show some other problems.

    1. Create a new folder for a repository
    2. Run hg init in that folder
    3. Run hg serve --cmdserver pipe
    4. Use Ctrl + C to break

    You should get an output like this:

    d:\Work\Mercurial\Tests3>md test2
    
    d:\Work\Mercurial\Tests3>cd test2
    
    d:\Work\Mercurial\Tests3\test2>hg init
    *** failed to import extension fold: No module named fold
    
    d:\Work\Mercurial\Tests3\test2>hg serve --cmdserver pipe
    *** failed to import extension fold: No module named fold
    o   5capabilities: getencoding runcommand
    encoding: cp1251
    

    Then try the following:

    1. Run hg serve --cmdserver pipe > log.txt
    2. Use Ctrl + C to break

    You should get the output like this:

    d:\Work\Mercurial\Tests3\test2>hg serve --cmdserver pipe > log.txt
    *** failed to import extension fold: No module named fold
    
  4. Pavel Kolotey

    Output for the first test (interrupted! prints after Ctrl+C):

    E:\Poul_Ko>md test
    
    E:\Poul_Ko>cd test
    
    E:\Poul_Ko\test>hg init
    *** failed to import extension fold: No module named fold
    
    E:\Poul_Ko\test>hg serve --cmdserver pipe
    *** failed to import extension fold: No module named fold
    o   5capabilities: getencoding runcommand
    encoding: cp1251interrupted!
    

    Output for the second test:

    E:\Poul_Ko\test>hg serve --cmdserver pipe > log.txt
    *** failed to import extension fold: No module named fold
    interrupted!
    

    log.txt file is attached.

  5. Sergey Antonov repo owner

    The output looks fine. I hoped it may contain some additional information about issue, but it is not.

    So, currently I'm out of ideas about why you hit this issue.

    The only way I can get the 'arithmetic overflow' error is when I'm trying to run mercurial in a cmdserver mode in a folder, that is not under mercurial repository. (This is a limitation of command server mode).

    It should not be possible to get that in a HgSccPackage normaly, because it is either:

    • Creates a new repository by hg init first and then run cmdserver in that folder
    • Or, when you loading a solution/project it will check the path for existing repository by hg root, before running a cmdserver there
  6. Pavel Kolotey

    When adding solution to source control hg repository created successfully, but no files added. Exception happens between hg init and adding files.

    I tried to reproduce the error using the following code, but unsuccefully.

                using (HgScc hgscc = new HgScc())
                {
                    SccErrors err = hgscc.OpenProject(@"C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1", SccOpenProjectFlags.None);
                    if (err != SccErrors.Ok)
                    {
                        err = hgscc.OpenProject(@"C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1", SccOpenProjectFlags.CreateIfNew);
    
                        if (err != SccErrors.Ok)
                            Debugger.Break();
    
                        Console.WriteLine("Created...");
                    }
                    else Console.WriteLine("Opened...");
    
                    foreach (var pair in hgscc.QueryInfoFullDict())
                    {
                        var file = pair.Key;
                        var status = pair.Value;
    
                        Console.WriteLine("{0}\t{1}", Path.Combine(hgscc.WorkingDir, file).ToLower(), status.Status);
                    }
    
                    Console.WriteLine();
                    Console.WriteLine("Adding files");
    
                    SccAddFile solutionFile = new SccAddFile() { File = @"C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1\ConsoleApplication1.sln", Flags = SccAddFlags.FileTypeAuto };
                    hgscc.Add(IntPtr.Zero, new SccAddFile[] { solutionFile }, "Adding files");
                   
                    Console.ReadLine();
               }
    

    Can you build for me special version with detailed logging? Log can help to locate the point where exception occurs.

  7. Sergey Antonov repo owner

    I've built a HgSccPackage with detailed logging enabled (hgsccpkg190_logs.zip attached to this issue).

    Can you install it, then do steps to reproduce an issue?

    The resulting log should be located at: c:\Users\[YourUserName]\AppData\Local\HgSccPackage\hgsccpkg.log

    The log file is recreated on each IDE startup.

    By the way, If you have VS2008, then you could debug it more easily in the experimental hive https://bitbucket.org/zzsergant/hgsccpackage/wiki/Development

  8. Pavel Kolotey

    Thanks, I reproduced the issue. Log followed.

    Found extension: convert
    Found extension: children
    Found extension: color
    Found extension: eol
    Found extension: extdiff
    Found extension: fetch
    Found extension: fold
    Found extension: mq
    Found extension: progress
    Found extension: purge
    Found extension: rebase
    Found extension: relink
    Found extension: transplant
    Found extension: record
    Found extension: win32mbcs
    Entering constructor for: Microsoft.DocWellBehavior.DocWellBehaviorPackage
    Entering Initialize() of: Microsoft.DocWellBehavior.DocWellBehaviorPackage
    Entering constructor for: Microsoft.VSProjectPlus.AddReferencePackage
    Entering Initialize() of: Microsoft.VSProjectPlus.AddReferencePackage
    OpenProject: C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1, flags None
    Root not exists
    OpenProject: C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1\ConsoleApplication1, flags None
    Root not exists
    Entering Initialize() of: Microsoft.VisualStudio.TeamArchitect.DesignersCommon.DesignersCommonPackage
    DPStudio.VSCommands, Version=1.0.0.0, Culture=neutral, PublicKeyToken=b47457c63258c69c
    Entering constructor for: Microsoft.VsWizards.ImportProjectFolderWizard.NewProjectFromExistingPackage
    Entering Initialize() of: Microsoft.VsWizards.ImportProjectFolderWizard.NewProjectFromExistingPackage
    QuickAccess has completed all background indexing.
    devenv.exe Information: 0 : Information: Cannot contact VSG.
    OpenProject: C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1, flags None
    Root not exists
    OpenProject: C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1, flags CreateIfNew
    Root not exists
    Creating a repository: C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1
    Repository created
    Opening a command server client: C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1
    Creating new process:
    - Filename         = C:\Program Files\TortoiseHg\hg.exe
    - WorkingDirectory = C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1
    - Arguments        = serve --cmdserver pipe
    Assign process to job failed
    Reading hello message
    Exception : Arithmetic operation resulted in an overflow.
    StackTrace:    at HgSccHelper.CommandServer.Message.Reserve(UInt32 size)
       at HgSccHelper.CommandServer.HgCmdServer.ReadChannel(Message& msg)
       at HgSccHelper.CommandServer.HgClient.ReadHello()
       at HgSccHelper.CommandServer.HgClient.Open(String work_dir)
       at HgSccHelper.HgScc.OpenProject(String local_proj_path, SccOpenProjectFlags flags)
    
  9. Pavel Kolotey

    Overflow exception occurs during Message.Data array creation. Overflow exception happens when negative length is specified. The 'size' parameter type is uint and its value cannot be negative, but when creating array the value treats as int32. So, I think the cause is too big size value (more than 2147483647).

    What about 'Assign process to job failed' error? Can it explain this situation?

  10. Sergey Antonov repo owner

    I think that 'Assing process to job failed' error is because the process was allready exited with an error. And the HgSccPackage could not read hello message from the server for the same reason.

    For some reason mercurial can not run in command server mode for that project.

    Please, run the following command in the command line:

    "C:\Program Files\TortoiseHg\hg.exe" -R "C:\Users\Poul_Ko\Documents\Visual Studio 2010\Projects\ConsoleApplication1" serve --cmdserver pipe

    It should fail and probably show some additional error message.

  11. Pavel Kolotey

    It prints

    *** failed to import extension fold: No module named fold
    o   5capabilities: getencoding runcommand
    encoding: cp1251
    

    I guess the plugin treats first line

    *** failed to import extension fold: No module named fold
    

    as hello message and asterisk symbols decoded to a big message size.

  12. Sergey Antonov repo owner

    Process with redirected I/O have several pipes:

    • standard input
    • standard output
    • standard error

    HgSccPackage uses only standard input and standard output when it run the hg.exe in command server mode.

    The *** failed to import extension fold: No module named fold message goes to standard error stream and should be ignored by HgSccPackage, because it run hg.exe process without redirection of the standard error pipe.

    Earlier, I asked you to run a hg serve --cmdserver pipe > log.txt where standard output was redirected to a file. From your output it is clearly seen, that stdout is redirected to log.exe, but error message goes to a standard error and shown in the console (i.e. not redirected). So, the standard output and standard error pipes are separated and are not mixed.

    In the IDE logs aboce there are a lot of extensions enabled. I remember, that you allready tried with all extension disabled (except fold), but can you try it again? To be sure, that the fold is the only enabled extension.

    The other ways to understand what is wrong is to use a Process Monitor tool (http://technet.microsoft.com/en-us/sysinternals/bb896645) to get an activity trace for hg.exe process. Maybe you will see an access to a missing files or some other errors. To filter only hg.exe activity use a ProcessName filter.

  13. Pavel Kolotey

    With only fold extension enabled (hg help prints

    *** failed to import extension fold: No module named fold
    

    and no enabled extensions section) the hgsccpkg.log file content is the same as posted before.

  14. Sergey Antonov repo owner

    Thanks for the logs. It seems I found a problem.

    Currently, when I run a mercurial in cmdserver mode with redirected output I uses a MS Visual Studio process standard error handle and pass it for a child process. Looks like this handle is not valid for some reason. Maybe some of the MS Visual Studio extension or addon put it in the bad state or closed it.

    When mercurial tries to write an error about missing extension to that pipe it aborts with error.

    I've made another build, where a dedicated pipe is created for a stdandard error (hgsccpkg190_logs2.zip). Can you please try it ?

  15. Pavel Kolotey

    I tried to disable all VS extensions, but behavior was the same.There is one VS plugin (Test Driven .NET) what was uninstalled incorrectly.

    hgsccpkg190_logs2.zip works well! It seems you really found the problem!

    Log attached ("Assign process to job failed" still presents).

  16. Sergey Antonov repo owner

    I'm glad to hear, that it is finally working for you. I will include a fix in the next HgSccPackage release.

    It is most probably, that job assigning has failed because the process is allready assigned to a job.

    For example, if the process is being monitored by the Program Compatibility Assistant (PCA), it is placed into a compatibility job. Therefore, the process must be created using CREATE_BREAKAWAY_FROM_JOB before it can be placed in another job.

    I've made another build with logs, where:

    • Added is process in any job check before assigning it to a new job
    • Added a job break away creation flag for a hg process, so it will have an opportunity to break from the existing job (if that is allowed by a job object)

    Can you check the attached build and show a log output?

  17. Pavel Kolotey

    There are a some extra log files (named like de8d5d9b-deb8-45f8-b398-eade57dfe2c7hgsccpkg.log) in AppData\Local\HgSccPackage folder. Is it important? Files was created yesterday when hgsccpkg190_logs2 was used.

    I've attach log created with new version. It seems there is no error messages in it.

    I'm glad to help you to improve this useful software.

  18. Sergey Antonov repo owner

    Great!

    I'll include both fixes to the next HgSccPackage release. Thank you for your patience with this remote debugging session.

    The extra log files are created by TextWriterTraceListener whenever an attempt is made to write to a file that is in use or unavailable, the file name is automatically prefixed by a GUID. I'm not sure why those are created in the first place, because it is supposed to be thread safe to use a trace listener. I'll look into that later.

  19. Log in to comment